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

Reduce the amount of logging from org.apache.http bundles. #2420

Merged
merged 1 commit into from
Jan 30, 2023

Conversation

rgrunber
Copy link
Contributor

@rgrunber rgrunber commented Jan 24, 2023

  • Some extensions to JDT-LS may introduce 'org.apache.http' bundles which logs excessively with messages of no real value
  • When jdt.ls.debug=true is passed as a system property, DEBUG logging is enabled at the root logger

In order to reproduce, let's take the vscode-java client and be sure to set java.jdt.ls.vmargs to include the system property -Djdt.ls.debug=true. Also make sure to install https://github.com/testforstephen/vscode-pde which should contain the bundle that will initiate this behaviour. Simply open eclipse.jdt.ls in the editor.

When monitoring the contents of $HOME/.config/Code/User/workspaceStorage/${jdt-ls-workspace-id}/redhat.java/jdt_ws/.metadata/ you should be able to see as part of the import something like :

total 9.9M
 4.0K .
 4.0K ..
1004K .bak_0.log
1004K .bak_1.log
1004K .bak_2.log
1004K .bak_3.log
1004K .bak_4.log
1008K .bak_5.log
1004K .bak_6.log
1004K .bak_7.log
1004K .bak_8.log
1004K .bak_9.log
    0 .error-jdt.ls-20230124154315.log
 4.0K .log
    0 .out-jdt.ls-20230124154315.log
 4.0K .plugins

If you watch the timestamps of those backup files, you'll see that they're constantly updated, because they're being overwritten every second (10 log files is the maximum set after which data rolls back to the start). The amount of logging is excessive enough to slow down the import process. Using iostat, I estimated at least 500MB of data, were written out similar to :

!ENTRY org.eclipse.jdt.ls.logback.appender 1 0 2023-01-20 16:13:19.915
!MESSAGE http-outgoing-272 << "][0xffffffb8][0xffffffe7][0xffffff85]I[0x0][0xffffffcf][0xffffffd1]n[0x1c]g9wm\[0x6][0xffffffef][0xffffffd0][0xffffff93][0x15]v[0xffffffb0]f[0xffffffba][0xffffffcc][0xffffff95][0x19][0xffffffe0][0x1e]Z[0x18][0x19]Ac[0xffffff9b]T[0x1e]kZ[0xffffffc1]kv[0xffffff90]B[0xfffffff0]%[0xffffffbf]A[0xffffff89][0x1]H'[0xffffffe5]upn[0xffffff93][0xffffffb7]Lq[[0xffffffeb][0xffffffbf]N[0xffffffcd][0xb]1[0xffffffe5][0xffffffc2].[0xffffffc3][0xffffff84][0x7]^c[0xffffffe0][0xfffffff3][0x17][0xffffff81][0x9]tl[0xfffffffa][0x8][0xffffffed][0xffffffd7][0xffffffa1]g[0x3][0xffffffa7][0xffffff9e]A[0x2][0xffffffd9]b-y[0xfffffffb][0xfffffff6][0xffffffad][0xffffffef]6[0xfffffff6]_l[0xfffffff8]l`[0xe][0xffffffce]Je[0xfffffffa]r%[0xffffffc6]go[0xfffffff6][0xffffffeb][0xffffffaa]M<f*[0xfffffffd][0xffffffad][0xffffffef]N[0xffffffd2]W[0xe][0xffffff8d]yg[0xffffffa2][0xffffffc2][0x1c][0xffffffc5][0xfffffff1][0xffffff9b]F[0x16][0xc]o&&[0xffffff83]0?[0x6]L[0x11],KJ[0xfffffff2][0x10]Z3w[0xffffff98][0xffffffa2][0xffffffb4][0x4][0xffffffc1][0xffffffd9]]{Y[\r][0xffffff93]9[0x1b][0x4]o[0xfffffff7][0xffffff8f][0xffffff83]7#[0xffffffcc]0d[0xffffff8b][0xffffffa5][0xfffffff1]H-[0xffffffc5]qnc$[0xffffff90][0x7f]v[0xffffffee][0xffffff9f][0x1e][0x12]i[0x8]h[0xffffffed][0xfffffff7]:w[0x7][0xffffff80][0xffffff98][0x17]/[0x7]a[0xfffffffe][0xffffff9d]p[0xffffffbe][0xffffffdf]I[0xffffff99][0xfffffffb][0xffffffda][0xfffffff9][0x1e]e[0xffffff8e][0xffffffd4][0xffffffdc]Y6[0x1][0xffffffbb][0xffffff99][0xffffffc1][0xffffffd6][0xffffff86]R@[0xfffffffa][0xfffffff9]K[0xffffff8b][0x1][0x1e][0xffffffd1][0xffffffab][0xffffff90][0xffffffa8]S[\r][0xffffffab][0xffffffa4][0xfffffff6]_[0xffffff87][0x19][0xffffff84][0xffffff92]=[0xffffffd0][0xffffff83][0xffffff85][0xffffffbe]'[0xffffff94][0xffffff9f][0xfffffff9][0x10][0xffffff9f][0xffffffbc][0xf][0xffffffca][0x9][0xe]O[0xffffffca][0xffffffbf][0x1e][0xfffffffd][0x1f]PK[0x7][0x8]<(.[0xffffffc4][0xfffffff4][\n]"

This PR should fix this. Although the bundle originates from vscode-pde, it's easier to include the code here than it is to suggest that vscode-pde add their own logback configuration bundle.

Signed-off-by: Roland Grunberg rgrunber@redhat.com

- Some extensions to JDT-LS may introduce 'org.apache.http' bundles
  which logs excessively with messages of no real value
- When jdt.ls.debug=true is passed as a system property, DEBUG logging is
  enabled at the root logger

Signed-off-by: Roland Grunberg <rgrunber@redhat.com>
@rgrunber rgrunber requested a review from jdneo January 24, 2023 21:02
Copy link
Contributor

@jdneo jdneo left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM.

The bug can be reproduced after setting -Djdt.ls.debug=true and then trigger reload target platform. And it's fixed after applying the patch.

@jdneo
Copy link
Contributor

jdneo commented Jan 30, 2023

// cc @testforstephen

@rgrunber
Copy link
Contributor Author

Thought I'd CC @sbouchet as he dealt with a similar case in a different stack. Basically this is a problem only when vscode-pde is installed, as it contributes the org.apache.httpcomponents.client5.httpclient5 bundle into the JDT-LS runtime. The problem is, in order to properly suppress it in vscode-pde, they'd have to create a custom configurator, which would mean a separate bundle, much like we do with https://github.com/eclipse/eclipse.jdt.ls/tree/master/org.eclipse.jdt.ls.logback.appender. This is just a fragment host of ch.qos.logback.classic, so that the framework can pick up https://github.com/eclipse/eclipse.jdt.ls/blob/8c334d898eaff15d75ac939c8e53a251c5440254/org.eclipse.jdt.ls.logback.appender/src/META-INF/services/ch.qos.logback.classic.spi.Configurator#L1 .

We used to have the logback configuration bundle back in 9f116c2 but opted for our own when we bumped to M2E 2.x. Also org.eclipse.m2e.logback.configurator got merged into org.eclipse.m2e.logback.appender in 4df09e69ba221bf7db7dceeac9e5ed666dfb5606 (2.1.x) so may need to keep track of where it goes down the road if you heavily depend on it.

@rgrunber rgrunber added this to the End February 2023 milestone Jan 30, 2023
@rgrunber rgrunber merged commit a21cb62 into eclipse-jdtls:master Jan 30, 2023
@rgrunber rgrunber deleted the reduce-http-logging branch January 30, 2023 19:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants