Skip to content

[LIVY-878] Replace log4j with reload4j - #392

Merged
dacort merged 15 commits into
masterfrom
fix/log4j-reload4j
Apr 26, 2023
Merged

[LIVY-878] Replace log4j with reload4j#392
dacort merged 15 commits into
masterfrom
fix/log4j-reload4j

Conversation

@dacort

@dacort dacort commented Mar 13, 2023

Copy link
Copy Markdown
Contributor

What changes were proposed in this pull request?

How was this patch tested?

  • unit/integration tests

@dacort dacort mentioned this pull request Mar 13, 2023
4 tasks
@dacort dacort changed the title initial attempt at reload4j and excluding transitive dependencies [LIVY-878] Replace log4j with reload4j Mar 14, 2023

@ksumit ksumit left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I noticed following in mvn dependency:tree output, the scope is test, so not that worrisome, but thought to bring to your attention.

[INFO] +- org.apache.directory.server:apacheds-server-integ:jar:2.0.0.AM26:test
[INFO] |  +- org.apache.directory.server:apacheds-core-annotations:jar:2.0.0.AM26:test
[INFO] |  |  +- org.apache.directory.mavibot:mavibot:jar:1.0.0-M8:test
[INFO] |  |  \- org.apache.directory.server:apacheds-mavibot-partition:jar:2.0.0.AM26:test
[INFO] |  +- org.apache.directory.server:apacheds-core-jndi:jar:2.0.0.AM26:test
[INFO] |  +- org.apache.directory.server:apacheds-interceptor-kerberos:jar:2.0.0.AM26:test
[INFO] |  +- org.apache.directory.server:apacheds-server-annotations:jar:2.0.0.AM26:test
[INFO] |  |  \- org.apache.directory.server:apacheds-protocol-kerberos:jar:2.0.0.AM26:test
[INFO] |  +- org.apache.directory.server:apacheds-test-framework:jar:2.0.0.AM26:test
[INFO] |  |  \- org.apache.directory.api:api-ldap-codec-standalone:jar:2.0.0:test
[INFO] |  |     \- org.apache.directory.api:api-ldap-net-mina:jar:2.0.0:test
[INFO] |  +- ldapsdk:ldapsdk:jar:4.1:test
[INFO] |  +- log4j:log4j:jar:1.2.17:test

@ayushtkn

Copy link
Copy Markdown
Member

If it isn't getting used, its better if we could exclude the log4j dependency completely even from test scope

@dacort

dacort commented Apr 7, 2023

Copy link
Copy Markdown
Contributor Author

AhI thought I addressed the apacheds-server-integ - will double-check that.

@ayushtkn Thanks, latest push should be better.

@lmccay lmccay left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

+1

@dacort

dacort commented Apr 8, 2023

Copy link
Copy Markdown
Contributor Author

Will trigger CI with a push today.

@dacort
dacort force-pushed the fix/log4j-reload4j branch from 7ff3ec1 to a59259c Compare April 8, 2023 22:15
@codecov-commenter

codecov-commenter commented Apr 8, 2023

Copy link
Copy Markdown

Codecov Report

Merging #392 (c616540) into master (80c6303) will increase coverage by 2.53%.
The diff coverage is n/a.

@@             Coverage Diff              @@
##             master     #392      +/-   ##
============================================
+ Coverage     65.95%   68.49%   +2.53%     
- Complexity      837      859      +22     
============================================
  Files           103      103              
  Lines          6063     6063              
  Branches        913      913              
============================================
+ Hits           3999     4153     +154     
+ Misses         1539     1344     -195     
- Partials        525      566      +41     

see 25 files with indirect coverage changes

📣 We’re building smart automated test selection to slash your CI/CD build times. Learn more

@dacort

dacort commented Apr 8, 2023

Copy link
Copy Markdown
Contributor Author

Bummer, CI failed. Will take a look either later today or Monday.

@dacort

dacort commented Apr 9, 2023

Copy link
Copy Markdown
Contributor Author

Integration tests are working, but unit tests still failing with, what I think is an error related to slf4j/log4j loading.

[INFO] Running org.apache.livy.thriftserver.session.ColumnBufferTest
[ERROR] Tests run: 5, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 2.572 s <<< FAILURE! - in org.apache.livy.thriftserver.session.ColumnBufferTest
[ERROR] testColumnBuffer(org.apache.livy.thriftserver.session.ColumnBufferTest)  Time elapsed: 2.147 s  <<< ERROR!
java.lang.NoClassDefFoundError: org/apache/log4j/Level
        at org.apache.livy.thriftserver.session.ColumnBufferTest.testColumnBuffer(ColumnBufferTest.java:53)
Caused by: java.lang.ClassNotFoundException: org.apache.log4j.Level
        at org.apache.livy.thriftserver.session.ColumnBufferTest.testColumnBuffer(ColumnBufferTest.java:53)

[INFO] Running org.apache.livy.thriftserver.session.ThriftSessionTest
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.024 s <<< FAILURE! - in org.apache.livy.thriftserver.session.ThriftSessionTest
[ERROR] org.apache.livy.thriftserver.session.ThriftSessionTest  Time elapsed: 0.024 s  <<< ERROR!
java.lang.ExceptionInInitializerError
        at org.apache.livy.thriftserver.session.ThriftSessionTest.setUp(ThriftSessionTest.java:60)
Caused by: java.lang.IllegalStateException: org.slf4j.LoggerFactory in failed state. Original exception was thrown EARLIER. See also http://www.slf4j.org/codes.html#unsuccessfulInit
        at org.apache.livy.thriftserver.session.ThriftSessionTest.setUp(ThriftSessionTest.java:60)

@dacort

dacort commented Apr 11, 2023

Copy link
Copy Markdown
Contributor Author

Fixed the java.lang.NoClassDefFoundError error with additional exclusions.

Unit tests are failing, however I think it's due to a flaky test based on behavior observed in CI where unit tests pass on the PR but fail once merged into master and vice-cersa.

There's an old mailing list thread that also discusses the issue, but with no resolution.

The second error, TestSparkClient.testJobSubmission, is random. I see the
failure ~25% of the times. As it turned out, the Echo job was returning,
sometimes, even before we added the listener on the job handle. So the
listener.onJobStarted method is not invoked. This can be fixed in multiple
ways but I updated the Echo job, which used to simply return its attribute
value, to do what ScalaEcho job is doing. So the Echo job now returns
"jc.sc().parallelize(list,
1).collect().get(0);". Even this could still be fast enough to cause the
same error. However I couldn't reproduce it again. Also the updated code is
taking ~1 sec or more on spark's side. So hopefully this should be ok.

@gyogal

gyogal commented Apr 12, 2023

Copy link
Copy Markdown
Contributor

Interesting, this test does seem to be flaky. The recent post-commit tests have succeeded, but that may be just pure luck. Could you please retrigger the tests on this one? If this test proves to be flaky, we should file a separate JIRA for it. Also, thanks for finding that old email thread about this test!

@dacort

dacort commented Apr 12, 2023

Copy link
Copy Markdown
Contributor Author

I've been poking at the failure for this change more and turns out it's something different. When I add exclusions for slf4j-log4j12 to spark-core, Netty fails to find slf4j logger, instead tries to use log4j and, I think, ends up failing. If I don't add that exclusion, the test runs fine.

  • without slf4j-log4j12 exclusion
23/04/12 15:16:09 DEBUG InternalLoggerFactory: Using SLF4J as the default logging framework
  • with slf4j-log4j12 exclusion
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
23/04/12 15:25:58 DEBUG InternalLoggerFactory: Using Log4J as the default logging framework

The InternalLoggerFactory message is coming from Netty.

I'm still trying to figure out what exactly is going on there but not having much luck. In most other PRs I've seen for reload4j, slf4j-log4j12 is included in the exclusions.

@dacort

dacort commented Apr 12, 2023

Copy link
Copy Markdown
Contributor Author

Might have figured this out! Swapping slf4j-api with slf4j-reload4j seems to get me past TestSparkClient. Running the full suite now.

@lmccay

lmccay commented Apr 18, 2023

Copy link
Copy Markdown
Contributor

@dacort - looks like the same failures?

@dacort

dacort commented Apr 18, 2023

Copy link
Copy Markdown
Contributor Author

@lmccay Yes but I've got another working branch over here https://github.com/apache/incubator-livy/tree/fix/log4j-reload4j-part2 that appears to be working. Just need to verify everything looks good.

@lmccay

lmccay commented Apr 24, 2023

Copy link
Copy Markdown
Contributor

@dacort - curious where you are with the separate branch and plan here?

@dacort
dacort force-pushed the fix/log4j-reload4j branch from 9a0f832 to c616540 Compare April 25, 2023 22:33
@dacort

dacort commented Apr 26, 2023

Copy link
Copy Markdown
Contributor Author

@lmccay @ksumit OK! I've merged in changes from my working branch. Tests are green! (After some manual retries...)

Could y'all take one more glance at this and the I think it's good to merge in. Apologies this has taken so long, appreciate your patience and follow ups. 🙏

@lmccay lmccay left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

LGTM!

+1

@ksumit ksumit left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

I see we are keeping slf4j-reload4j as provided dependency, that means, it won't be bundled in the release, is that ok? how would this be available at runtime? can we please do a check on the release tarball if this jar magically appears or not?

@dacort

dacort commented Apr 26, 2023

Copy link
Copy Markdown
Contributor Author

slf4j-reload4j as provided dependency

I'll check, but it is defined as a non-provided dependency in the main pom.xml.

@ksumit

ksumit commented Apr 26, 2023

Copy link
Copy Markdown
Contributor

Given that this has taken us quiet some time, i do want to checkpoint this work and iterate over if there are issues. Approving for check-in.

+1, LGTM

@dacort
dacort merged commit 12505dd into master Apr 26, 2023
@dacort
dacort deleted the fix/log4j-reload4j branch April 26, 2023 17:14
jimenefe pushed a commit to onedot-data/incubator-livy that referenced this pull request Oct 15, 2024
* Replace log4j with reload4j along with relevant exclusions in dependencies
* Bump surefire to fix build
* Swap slf4j-api with slf4j-reload4j
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.

6 participants