Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Filter excessive logging of artifact download from m2e in "debug mode" #3011

Merged
merged 1 commit into from
Jan 5, 2024

Conversation

rgrunber
Copy link
Contributor

@rgrunber rgrunber commented Jan 4, 2024

See #2420, #2785 for some background on what the problem is.

When opening a Maven project whose contents have never been downloaded to the local repository (eg. a clean $HOME/.m2/repository), and with the system property jdt.ls.debug=true enabled (most commonly in java.jdt.ls.vmargs via. -D), the client and server logs will be overwhelmed with many messages of the form :

client log

[Info  - 13:39:08] Jan. 4, 2024, 1:38:35 p.m. http-outgoing-1 << "[0x0][0x0][0x8][0x0][0x0]N[0xb0][0xab]V[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0];[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x10][0x0][0xed]A@[0x1][0x0][0x0]META-INF/maven/org.codehaus.mojo/build-helper-maven-plugin/PK[0x1][0x2][0x14][0x3][\n]"
[Trace - 13:39:08] Received notification 'window/logMessage'.
Params: {
    "type": 3,
    "message": "Jan. 4, 2024, 1:38:35 p.m. http-outgoing-1 << \"[0x0][0x0][0x8][0x0][0x0]N[0xb0][0xab]V[0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x4][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x0][0x10][0x0][0xed]A[0x99][0x1][0x0][0x0]org/PK[0x1][0x2][0x14][0x3][\\n]\""
}

server log

!ENTRY org.eclipse.jdt.ls.logback.appender 1 0 2024-01-04 13:39:11.561
!MESSAGE http-outgoing-8 << "=~5[0xa9][0x83]OU[0xb5][0x97][0xa8][0xab][0x2]c[0xd2][0x86][0xfc]Um]V[0xd5]8W[0xf5][0xda]mY[0xd6]V[0xae]j[0xeb]a_Q[0x9b]Z[0xbd][0xa2]j[0x87][0x97]J[0xba][0xf1][0xb6][0x97]}[0x96][0x9e][0x0][0x88]FDE[0x13][0xea][0xc4]:[0xa4]E36[0x8b][0x16][0xb4][0x8b]4![0xd8][0x80]N[0xd1][0x8a]cB[0xc1][0xa0][0xd8]$[0x11]([0xf2][0xd1][0x1b][0xf2][0xaa]8[0x84][0x13][0xf2]I[0xcc]Q[0xfd][0x8f][0x91][0x16][0xf4]*V[0xf7][0x18]m![0x1f][0xb0][0x10]^?[0x88][0xb8]7z[0x87]{[0xa3][0x3][0xc1]e[0xcd]/r>[0x9e][0x2]n[0x94][0x10]^?[0xb8][0xb8][0x96][0xbd]rN[0x7][0xef],3<[0xe8]{[0xb1][0x85][0x97][0x9e][0xf0][0x9a]LxM&[0xdc]&[0xb][0xf0][0xe7][0x91][0xcb][0xf4][0xa8][0xfb][0xe8]6fC[0xfc]n[0xde]E[0xfc][0x6]j[0x1e]@[0xa1][0xde][0xd8][0xf8](Pm|[0xf9]v[0x8a]>[0x84][0xc5][0x9]$E?[0xea][0xc5][0x80]/[0xe1]F_a[0xe9][0x15][0xab][0xf7][0xd0]+[0xf4]?%[0x13][0x1e][0xfa][0x1f]PK[0x3][0x4][0x14][0x0][0x0][0x8][0x8][0x0]Hy6PE*[0x92],[0xe9][0x1][0x0][0x0][0x12][0x4][0x0][0x0]@[0x0][0x0][0x0]org/apache/commons/io/input/ObservableInputStream$Observer.class[0x9d]RMo[0xd3]@[0x14][0x9c][0xe7]8q[0x13][0x2][0xfd][0xa2][0xa5][0x94][0xcf][0xd2][0x82]B+a[0x90][0x80]C[qh[0x5][0xc2]RD[0xf][0x85]^*!m[0x9c]u[0xe2][0xc8][0xf1]Fk;[0xe2]oqB[0xe2][0x0]w~[0x14][0xe2][0xed][0xc6]-%D [0xb0]d[0xef][0x9b][0xdd][0x99]y[0xb3]O[0xfe][0xf6][0xfd][0xf3][0x17][0x0]O[0xf1][0xa0][0x81][\n]"

This breaks the import as no progress can be made. Luckily this is mostly a problem for those developing as we're more likely to be using jdt.ls.debug.

Looking at the logger's that are generating these, I found org.apache.http.wire generating a lot of messages. After disabling it I was able to get the project to import and noticed this distribution for logging messages :

      1 aQute.bnd.metatype.MetatypeAnnotations
      1 org.eclipse.buildship.core.internal.util.gradle.PublishedGradleVersions
      1 org.eclipse.m2e.core.internal.project.registry.ProjectProcessingTracker
      1 org.eclipse.m2e.core.internal.project.registry.ProjectRegistryRefreshJob
      2 org.eclipse.m2e.core.internal.markers.MavenMarkerManager
      2 org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager
      3 aQute.bnd.osgi.PluginsContainer
      3 org.eclipse.jgit.util.SystemReader
      4 org.eclipse.aether.internal.impl.synccontext.named.NamedLockFactoryAdapterFactoryImpl
      4 org.eclipse.m2e.core.internal.embedder.EclipseLogger
      4 org.eclipse.m2e.core.internal.project.registry.DefaultMavenDependencyResolver
      5 org.eclipse.m2e.jdt.internal.AbstractJavaProjectConfigurator
      6 org.eclipse.jgit.util.FS
      6 org.eclipse.m2e.core.internal.builder.MavenBuilder
      9 org.eclipse.m2e.core.internal.project.ProjectConfigurationManager
     10 org.eclipse.m2e.core.internal.lifecyclemapping.LifecycleMappingFactory
     18 aQute.bnd.osgi.Processor
     19 aQute.bnd.osgi.Analyzer
     19 aQute.bnd.osgi.Contracts
     19 org.eclipse.jgit.internal.storage.file.Pack
     20 org.eclipse.m2e.core.internal.builder.MavenBuilderImpl
     23 org.eclipse.aether.internal.impl.DefaultLocalRepositoryProvider
     27 org.eclipse.aether.internal.impl.collect.bf.BfDependencyCollector
     40 org.apache.http.impl.conn.DefaultHttpClientConnectionOperator
     54 org.eclipse.m2e.core.project.configurator.AbstractCustomizableLifecycleMapping
    114 org.eclipse.jgit.internal.storage.file.FileSnapshot
    200 org.apache.http.conn.ssl.SSLConnectionSocketFactory
    848 org.eclipse.aether.internal.impl.DefaultRepositoryConnectorProvider
    848 org.eclipse.aether.internal.impl.DefaultTransporterProvider
    924 org.eclipse.aether.internal.impl.DefaultArtifactResolver
    960 org.apache.maven.shared.filtering.DefaultMavenResourcesFiltering
   1222 org.apache.http.client.protocol.RequestAddCookies
   1682 org.eclipse.aether.internal.impl.DefaultTrackingFileManager
   1682 org.eclipse.m2e.core.internal.embedder.AbstractTransferListenerAdapter
   3656 org.apache.http.impl.conn.DefaultManagedHttpClientConnection
   4890 org.apache.http.impl.conn.PoolingHttpClientConnectionManager
   4908 org.apache.http.impl.execchain.MainClientExec
  23536 org.apache.http.headers

I think it's safe to disable org.apache.http entirely (and I've also modified an existing one).

Signed-off-by: Roland Grunberg <rgrunber@redhat.com>
@rgrunber rgrunber merged commit 222f3fa into eclipse-jdtls:master Jan 5, 2024
7 checks passed
@rgrunber rgrunber deleted the filter-artifact-dl branch January 5, 2024 05:24
@rgrunber rgrunber self-assigned this Jan 9, 2024
@rgrunber rgrunber added this to the Early January 2024 milestone Jan 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant