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

Graal optimizations may break uberjar running #378

Closed
TuggyNE opened this issue Oct 2, 2023 · 7 comments
Closed

Graal optimizations may break uberjar running #378

TuggyNE opened this issue Oct 2, 2023 · 7 comments
Assignees
Milestone

Comments

@TuggyNE
Copy link

TuggyNE commented Oct 2, 2023

I recently upgraded Timbre and Tufte (as I use lein-ancient as part of my release scripting) and was surprised to discover a runtime failure on deployment. Local running is fine, uberjar building is fine, but on the server I get a stack trace that looks like this:

Exception in thread "main" java.lang.NoSuchFieldError: taoensso/timbre__init.__thunk__0__
	at taoensso.timbre__init.load(Unknown Source)
	at taoensso.timbre__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.core$load_one.invokeStatic(core.clj:5933)
	at clojure.core$load_one.invoke(core.clj:5928)
	at clojure.core$load_lib$fn__6850.invoke(core.clj:5975)
	at clojure.core$load_lib.invokeStatic(core.clj:5974)
	at clojure.core$load_lib.doInvoke(core.clj:5953)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$load_libs.invokeStatic(core.clj:6016)
	at clojure.core$load_libs.doInvoke(core.clj:6000)
	at clojure.lang.RestFn.applyTo(RestFn.java:137)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$require.invokeStatic(core.clj:6038)
	at clojure.core$require.doInvoke(core.clj:6038)
	at clojure.lang.RestFn.invoke(RestFn.java:421)
	at slf4j_timbre.adapter$loading__6737__auto____171.invoke(adapter.clj:1)
	at slf4j_timbre.adapter__init.load(Unknown Source)
	at slf4j_timbre.adapter__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.core$load_one.invokeStatic(core.clj:5933)
	at clojure.core$load_one.invoke(core.clj:5928)
	at clojure.core$load_lib$fn__6850.invoke(core.clj:5975)
	at clojure.core$load_lib.invokeStatic(core.clj:5974)
	at clojure.core$load_lib.doInvoke(core.clj:5953)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$load_libs.invokeStatic(core.clj:6016)
	at clojure.core$load_libs.doInvoke(core.clj:6000)
	at clojure.lang.RestFn.applyTo(RestFn.java:137)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$require.invokeStatic(core.clj:6038)
	at clojure.core$require.doInvoke(core.clj:6038)
	at clojure.lang.RestFn.invoke(RestFn.java:421)
	at slf4j_timbre.factory$loading__6737__auto____4342.invoke(factory.clj:1)
	at slf4j_timbre.factory__init.load(Unknown Source)
	at slf4j_timbre.factory__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.lang.Var.invoke(Var.java:384)
	at clojure.lang.Util.loadWithClass(Util.java:251)
	at com.github.fzakaria.slf4j.timbre.TimbreLoggerFactory.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at slf4j_timbre.static_logger_binder$_getLoggerFactoryClassStr.<clinit>(static_logger_binder.clj:20)
	at slf4j_timbre.static_logger_binder__init.load(Unknown Source)
	at slf4j_timbre.static_logger_binder__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.lang.Var.invoke(Var.java:384)
	at clojure.lang.Util.loadWithClass(Util.java:251)
	at org.slf4j.impl.StaticLoggerBinder.<clinit>(Unknown Source)
	at org.slf4j.LoggerFactory.bind(LoggerFactory.java:150)
	at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
	at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:417)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:362)
	at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155)
	at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:132)
	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:273)
	at org.apache.http.conn.ssl.AbstractVerifier.<init>(AbstractVerifier.java:61)
	at org.apache.http.conn.ssl.AllowAllHostnameVerifier.<clinit>(AllowAllHostnameVerifier.java:46)
	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.<clinit>(SSLConnectionSocketFactory.java:151)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clj_http.conn_mgr__init.__init0(Unknown Source)
	at clj_http.conn_mgr__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.core$load_one.invokeStatic(core.clj:5933)
	at clojure.core$load_one.invoke(core.clj:5928)
	at clojure.core$load_lib$fn__6850.invoke(core.clj:5975)
	at clojure.core$load_lib.invokeStatic(core.clj:5974)
	at clojure.core$load_lib.doInvoke(core.clj:5953)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$load_libs.invokeStatic(core.clj:6016)
	at clojure.core$load_libs.doInvoke(core.clj:6000)
	at clojure.lang.RestFn.applyTo(RestFn.java:137)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$require.invokeStatic(core.clj:6038)
	at clj_http.client$loading__6789__auto____795.invoke(client.clj:1)
	at clj_http.client__init.load(Unknown Source)
	at clj_http.client__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.core$load_one.invokeStatic(core.clj:5933)
	at clojure.core$load_one.invoke(core.clj:5928)
	at clojure.core$load_lib$fn__6850.invoke(core.clj:5975)
	at clojure.core$load_lib.invokeStatic(core.clj:5974)
	at clojure.core$load_lib.doInvoke(core.clj:5953)
	at clojure.lang.RestFn.applyTo(RestFn.java:142)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$load_libs.invokeStatic(core.clj:6016)
	at clojure.core$load_libs.doInvoke(core.clj:6000)
	at clojure.lang.RestFn.applyTo(RestFn.java:137)
	at clojure.core$apply.invokeStatic(core.clj:669)
	at clojure.core$require.invokeStatic(core.clj:6038)
	at <our.main-ns>$loading__6789__auto____171.invoke(main_ns.clj:1)
	at <our.main-ns>__init.load(Unknown Source)
	at <our.main-ns>__init.<clinit>(Unknown Source)
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:407)
	at clojure.lang.RT.classForName(RT.java:2209)
	at clojure.lang.RT.classForName(RT.java:2218)
	at clojure.lang.RT.loadClassForName(RT.java:2237)
	at clojure.lang.RT.load(RT.java:449)
	at clojure.lang.RT.load(RT.java:424)
	at clojure.core$load$fn__6908.invoke(core.clj:6161)
	at clojure.core$load.invokeStatic(core.clj:6160)
	at clojure.core$load.doInvoke(core.clj:6144)
	at clojure.lang.RestFn.invoke(RestFn.java:408)
	at clojure.lang.Var.invoke(Var.java:384)
	at clojure.lang.Util.loadWithClass(Util.java:251)
	at <our.main-ns>.<clinit>(Unknown Source)

It looks like it could be a subtle unexpected side effect of recent changes to optimize GraalVM builds.

It's possible that this only shows up when using the SLF4J adapter for Timbre, which is third-party. I don't have a great way to test without that currently, but I could work up a more minimal complete example if needed.

@ptaoussanis
Copy link
Member

@TuggyNE Hi there, thanks for the report!

Requesting a bit more info please-

  • What SLF4J adapter are you using? Could you please link me to it?
  • Have you tried clearing all your build artifacts?
  • Besides updating Timbre and Tufte, did you update anything else? E.g. JVM, Graal options, etc.

Thanks!

@ptaoussanis ptaoussanis self-assigned this Oct 3, 2023
@TuggyNE
Copy link
Author

TuggyNE commented Oct 3, 2023

What SLF4J adapter are you using? Could you please link me to it?

https://github.com/fzakaria/slf4j-timbre

Have you tried clearing all your build artifacts?

Yes, but it doesn't help. (I did confirm it's not architecture or OS-dependent, though.)

Besides updating Timbre and Tufte, did you update anything else? E.g. JVM, Graal options, etc.

Nope, totally routine build. (I don't actually use GraalVM NI for anything on this project, it's just a plain uberjar.)

Thanks!

You're welcome, and thanks for the quick reply!

@ptaoussanis
Copy link
Member

Can you share the version of Timbre that were you upgrading from? (May be helpful to pinpoint when an issue was introduced).

From your stacktrace, it looks to me like the problem might be with the appender, thought it's not immediately obvious to me what change/s might have caused trouble.

It looks like it could be a subtle unexpected side effect of recent changes to optimize GraalVM builds.

That change only affects unit tests, so I don't believe should affect your build.

I'd recommend opening an issue with slf4j-timbre. That project's maintainer can maybe more easily identify the problem from the stacktrace. If it turns out there was some kind of regression on Timbre's side, or if there's something I can do from Timbre's side to workaround the problem - I'll of course get right on it.

In the meantime am hoping they might be able to provide some guidance.

@ptaoussanis
Copy link
Member

Relatedly, have also just opened fzakaria/slf4j-timbre#71

@rufoa
Copy link

rufoa commented Nov 20, 2023

Thanks for bringing this up @TuggyNE!

Am I to understand that slf4j-timbre previously worked correctly under GraalVM? (I remember someone trying this out a while ago, but I don't recall the outcome.)

I'll aim to incorporate GraalVM into slf4j-timbre's integration tests so we can figure out any problems and avoid regressions.

@ptaoussanis
Copy link
Member

Just an update to mention that I'm planning a major Timbre update around Jul-Aug that will include out-the-box SLF4J integration and that will be covered by Timbre's own test suite.

@ptaoussanis
Copy link
Member

v6.6.0-RC1 is out now, with built-in SLF4J support 👍

Closing

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

No branches or pull requests

3 participants