Fork me on GitHub
#graalvm
<
2021-11-24
>
genekim18:11:30

@borkdude Congrats on your fantastic successes and creations — it’s been super fun hearing you share this new chapter in your life, and seeing the great things you’ve been creating!

❤️ 1
genekim18:11:50

After years of never quite making native images work, I’m committed to get something I run in Google Cloud Run to work. I seem to be stuck with something in cheshire library, I’m pretty sure that’s coming from transit, that’s being used by metosin/reitit-middleware. (Looking at clj -Stree.) I’m down to 3 errors — does anyone have any suggestions? (I’m 3 hours into this, and have made quite a mess. Upgrading deps, running uberjar with agents creating reflect-config.json files, ripping out cheshire for clojure.data.json, only to find out it’s still being used by reitit.) Many thanks in advance! (Full error message here: https://0bin.net/paste/AUvflgiG#PqRvpiXaTIOqR3HT5N1cW05kXeCQqGW333jf7YtCWX3. Thx to @igrishaev for teaching me about http://0bin.net. 🙂

Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_json_factory.invokeStatic(java.lang.Object) 
Parsing context:
   at cheshire.factory$make_json_factory.invokeStatic(factory.clj:28)
   at cheshire.factory$make_json_factory.invoke(factory.clj:28)
   at clojure.lang.MultiFn.invoke(MultiFn.java:229)
   at clojure.lang.AFn.applyToHelper(AFn.java:154)
   at clojure.lang.AFn.applyTo(AFn.java:144)
   at web.server.main(Unknown Source)
   at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147)
   at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183)

Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_cbor_factory.invokeStatic(java.lang.Object) 
Parsing context:
   at cheshire.factory$make_cbor_factory.invokeStatic(factory.clj:84)
   at cheshire.factory$make_cbor_factory.invoke(factory.clj:84)
   at clojure.lang.MultiFn.invoke(MultiFn.java:229)
   at clojure.lang.AFn.applyToHelper(AFn.java:154)
   at clojure.lang.AFn.applyTo(AFn.java:144)
   at web.server.main(Unknown Source)
   at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147)
   at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183)

Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_smile_factory.invokeStatic(java.lang.Object) 
Parsing context:
   at cheshire.factory$make_smile_factory.invokeStatic(factory.clj:57)
   at cheshire.factory$make_smile_factory.invoke(factory.clj:57)
   at clojure.lang.MultiFn.invoke(MultiFn.java:229)
   at clojure.lang.AFn.applyToHelper(AFn.java:154)
   at clojure.lang.AFn.applyTo(AFn.java:144)
   at web.server.main(Unknown Source)
   at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147)
   at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183)

borkdude18:11:45

@U6VPZS1EK cheshire isn't related to transit as far as I know. and I've never had a problem with cheshire, but it does need some configuration

borkdude18:11:26

@U6VPZS1EK There are a few things that you need to do. First of all, use --initialize-at-runtime

🤯 1
borkdude18:11:49

o no wait, you're using graal-build-time already, this is good

borkdude18:11:43

So this is the hint. > com.fasterxml.jackson.core.io.SerializedString

borkdude18:11:10

You need to also initialize that package at build time.

--initialize-at-build-time=com.fasterxml.jackson

borkdude18:11:34

> No instances of com.fasterxml.jackson.core.io.SerializedString are allowed in the image heap as this class should be initialized at image runtime.

borkdude18:11:19

Then there are these warnings: > > clj-easy/graal-build-time] WARN: Single segment package found for class: java_time__init.class. This class has no package and it will not be added to the result packages. > [clj-easy/graal-build-time] WARN: Single segment package found for class: clj_tuple__init.class. This class has no package and it will not be added to the result packages. > [clj-easy/graal-build-time] WARN: Single segment package found for class: potemkin__init.class. This class has no package and it will not be added to the result packages.

genekim18:11:03

Whew. Do you have a repo that shows how configuration required with cheshire? Ya, I saw those, but don’t know what to do with them…. Ohhhhh…. Trying it now. Roger — I think I’m starting to understand. Can I submit a PR to add jackson explanation somwhere, say, https://github.com/clj-easy/graal-docs?

borkdude18:11:31

There is no workaround for this other than to just do --initialize-at-build-time=. as those Clojure namespaces do not generate a Clojure package.

borkdude18:11:13

Actually we have packaged configs for a few libraries here already: https://github.com/clj-easy/graal-config

borkdude18:11:24

Including cheshire

borkdude19:11:16

It is also possible to contribute this config to cheshire so it will work automatically

borkdude19:11:18

I think another classic is that you're initializing components in top level defs.

env: telepresence:  nil
dbhost:  127.0.0.1
env: telepresence:  nil
dbhost:  127.0.0.1

borkdude19:11:28

But as I can't see the code, I'm not sure about that ;)

borkdude19:11:26

When you initialize everything at build time, those vars will get initialized in the image at compile time. You will need to delay those using delay or a normal function and then initialize in your -main function.

genekim19:11:55

This is starting to make sense… 1. What do I do with the single segment packages? Something like: --initialize-at-build-time=com.fasterxml.jackson,java_time,clj_tupe,potemkin? 2. configs: I saw you mention that above… ah, so worst case, just append those to --initialize-at-run-time. 3. Ah yes, running in top-level def. That was something I wrote 6 years ago when I didn’t know any better…. I know how to fix that one! 🙂 Thx for the help here, @borkdude — I’m finally experiencing that strange experience of “@borkdude just materializes out of nowhere and helps you.” I appreciate it!

borkdude19:11:36

1. as the Clojure namespace java-time doesn't generate packages, but just top level classes, you have no other option than to initialize everything at runtime (or to enumerate all the generated classes by Clojure for this namespace, which is painful). You can do this by --initialize-at-build-time=.. But in general it's better to avoid this and ask those libs to don't use single segment namespaces.

borkdude19:11:38

I've also experienced problems with the java-time library and GraalVM. Imo it's better to get rid of it (for this project) and use java.time interop directly, if you can. This library uses eval which doesn't play nicely with GraalVM, even if you do it at compile time.

genekim19:11:28

Am I doing this right? I’m using these flags, and getting a ton of new errors about classes being requested to be initialized at run time…

--initialize-at-build-time=com.fasterxml.jackson \
             --initialize-at-build-time=clojure,cheshire \
             --initialize-at-run-time=java_time,clj_tupe,potemkin \ 
 
java_time.temporal$fn__13341 the class was requested to be initialized at run time (from the command line with 'java_time'). To see why java_time.temporal$fn__13341 got initialized use --trace-class-initialization=java_time.temporal$fn__13341
potemkin.types$deftype__GT_deftype_STAR_ the class was requested to be initialized at run time (from the command line with 'potemkin'). To see why potemkin.types$deftype__GT_deftype_STAR_ got initialized use --trace-class-initialization=potemkin.types$deftype__GT_deftype_STAR_
potemkin.macros$gensym_QMARK_ the class was requested to be initialized at run time (from the command line with 'potemkin'). To see why potemkin.macros$gensym_QMARK_ got initialized use --trace-class-initialization=potemkin.macros$gensym_QMARK_
potemkin.collections$def_map_type the class was requested to be initialized at run time (from the command line with 'potemkin'). To see why potemkin.collections$def_map_type got initialized use --trace-class-initialization=potemkin.collections$def_map_type

borkdude19:11:09

yeah, no, read what I wrote at the answer to 1. :)

borkdude19:11:31

just use --initialize-at-build-time=. . there is no other way

borkdude19:11:39

(notice the dot)

borkdude19:11:52

the problem is the single segment namespace

genekim19:11:11

Ah. Giving that a try. (And I just learned how the configs work, by including them in deps.edn. Will eventually try that, too.). Okay, pull slot machine lever again! 🙂

borkdude19:11:32

This is what happens if you compile a single segment namespace:

$ echo '(ns foo)' > src/foo.clj
$ clojure -M -e "(compile 'foo)"
foo
$ ls classes
clojure                              foo$fn__128.class                    foo$loading__6721__auto____126.class foo__init.class

borkdude19:11:52

There is no foo package, just top level classes starting with foo

borkdude19:11:40

and if you try --initialize-at-build-time=foo, native image looks for a package foo

genekim19:11:50

1. …continued. To confirm: --initialize-at-build-time=. inits all packages and classes, just as in the docs would be done with an emtpy string? (I don’t think I’ve ever had this many Chrome tabs open. I was hacking way on this late into the night last night. 🙂

borkdude19:11:24

yes, you can also omit the =. part but then it will warn you about that this will become deprecated in GraalVM 22

borkdude19:11:09

This was what we did before this warning. But then this warning made us create graal-build-time and graal-config .

genekim19:11:38

4. Holy cow. I’m down to a couples lines of errors! Can I fix this by doing --initialize-at-run-time=“.google.auth.oauth2.OAuth2Credentials,com.google.auth.oauth2.ServiceAccountCredentials,com.google.auth.oauth2.GoogleCredentials,com.google.cloud.NoCredentials,com.google.auth.oauth2.OAuth2Utils ?

To see how the classes got initialized, use --trace-class-initialization=com.google.auth.oauth2.OAuth2Credentials,com.google.auth.oauth2.ServiceAccountCredentials,com.google.auth.oauth2.GoogleCredentials,com.google.cloud.NoCredentials,com.google.auth.oauth2.OAuth2Utils
[pubsub-web-standalone:67102]     analysis: 135,298.37 ms,  6.53 GB
Error: Classes that should be initialized at run time got initialized during image building:
 com.google.auth.oauth2.OAuth2Credentials the class was requested to be initialized at run time (from the command line with 'com.google.auth.oauth2'). To see why com.google.auth.oauth2.OAuth2Credentials got initialized use --trace-class-initialization=com.google.auth.oauth2.OAuth2Credentials
com.google.auth.oauth2.ServiceAccountCredentials the class was requested to be initialized at run time (from the command line with 'com.google.auth.oauth2'). To see why com.google.auth.oauth2.ServiceAccountCredentials got initialized use --trace-class-initialization=com.google.auth.oauth2.ServiceAccountCredentials
com.google.auth.oauth2.GoogleCredentials the class was requested to be initialized at run time (from the command line with 'com.google.auth.oauth2'). To see why com.google.auth.oauth2.GoogleCredentials got initialized use --trace-class-initialization=com.google.auth.oauth2.GoogleCredentials
com.google.cloud.NoCredentials the class was requested to be initialized at run time (). To see why com.google.cloud.NoCredentials got initialized use --trace-class-initialization=com.google.cloud.NoCredentials
com.google.auth.oauth2.OAuth2Utils the class was requested to be initialized at run time (from the command line with 'com.google.auth.oauth2'). To see why com.google.auth.oauth2.OAuth2Utils got initialized use --trace-class-initialization=com.google.auth.oauth2.OAuth2Utils

borkdude19:11:42

4. This may be triggered by your top level defs

borkdude19:11:50

If you solve those the error may go away

borkdude19:11:23

top level defs are ok if you're starting a server, etc, but do it in a delay

borkdude19:11:30

so the server doesn't start during the image build

genekim19:11:07

4. Roger. But I’m pretty sure this is in a completely different library. Uses a Google Cloud jar. Is usage of --initialize-at-run-time correct?

borkdude19:11:07

Can you maybe post a new 0bin with the entire output?

borkdude19:11:15

Then we'll start a new thread from there

genekim19:11:28

(in the database library, I’m using korma, which is another can of worms… which I’ve been procrastinating on getting rid of… today might be a good day for that. 🙂 Roger on pasting out. Seriously, thanks for the help.

borkdude19:11:54

if you're looking for a korma replacement: honeysql is what I can recommend

borkdude19:11:31

ok, why did you write: > --initialize-at-run-time=com.google.auth.oauth2

genekim19:11:39

(Yes, it’s currently a frankenstein of korma, clojure.jdbc, and maybe even some honeysql in there. 🙂

genekim19:11:12

I was hoping that it would pickup all the things that oauth2 hierarchy. I’ll delete that.

borkdude19:11:28

but why do you want to avoid build time init of oauth2, do you have more info on that?

genekim19:11:08

Doh. I was just trying to make the error message go away. Let me take all those lines out and try again.

borkdude19:11:17

OK, the explanation of this output: You have requested to initialize everything at build time now. Except oauth2. But that also got initialized at build time, probably because one of your top level defs which execute something that needs that class (indirectly)

borkdude19:11:47

As the output is saying, you can trace what initialized it by using the suggested option

borkdude19:11:00

but you can also just delete it and try again

genekim19:11:26

Here’s the forked library that I created that is using the Google Oauth stuff. I don’t see any top level defs except a definition of an atom… so even that (time/now) causes a problem, and should be deferred? https://github.com/realgenekim/google-cloud/blob/master/src/google_cloud/oauth.clj

borkdude19:11:48

@U6VPZS1EK It doesn't only matter if the library itself doesn't use any top level initializations of java classes, it also matters what your app is doing.

borkdude19:11:28

e.g. if you lib has (defn foo [] (Initialize.)) but your app has (def x (foo)) then Initialize still gets initialized.

genekim19:11:19

Okay, you were right about the oAuth stuff. Totally different set of errors, but I remember getting some these last night. https://0bin.net/paste/LqV3bnXj#+HTAtbMocuVu+HZzwUTc4Kw3FgHIdvEwhSBJvRtz3NI

borkdude19:11:00

@U6VPZS1EK use clojure 1.10.3 or newer

borkdude19:11:29

(see topic of this channel: the number 1 rule here ;))

genekim19:11:51

Drats. I must have missed that somewhere. (I’m using 5 local/root components.).

borkdude19:11:43

I see your app is pulling in a bunch of clojure.spec stuff. I don't know if you use any run time instrumentation or checking, but probably ghostwheel and orchestra you may want to turn off and leave outside of the deployed jar, this will give you a smaller binary

borkdude19:11:18

but this can be a later optimization

genekim19:11:11

Roger that. ^^. PS: I promise to write up all the bumps along the way, and put it someplace, and submit a PR for docs someplace. Okay, trying again with updated deps.

borkdude19:11:54

clojure 1.10.3 is specifically important since this has a fix for the locking macro. if you use spec in your app, you will likely hit that unbalanced monitor "bug" with earlier versions of clojure

genekim19:11:22

Yes, I saw that traffic way back when — delighted (and super impressed) at how quickly your changes are making it into clojure.core/etc. You’re in rarified air!

borkdude19:11:55

oh it wasn't my fix but I was super happy that issue got solved - the workaround was pretty gnarly

genekim19:11:22

It’s been years since I’ve dealt with compile times in my daily work. 🙂 And I’m afraid to close any of these tabs…

genekim19:11:56

PS: I watched this video yesterday, and thought of posting this here: https://www.youtube.com/watch?v=lqKTPnWUmvs It was what made me decide to invest some time to make native image work. The notion that these long build times are what would normally get amortized during multi-day JIT runs. Super compelling case for Graal AOT.

borkdude19:11:08

It's often best to start with a trivial amount of code and then start adding stuff.

borkdude19:11:26

both to check if things work and also to monitor the image size (if you care about that)

genekim19:11:20

Yes, the wisdom of that is quite clear right now. 🙂 Sunk cost fallacy killing me right now. 🙂 I’m getting same unbalanced monitor error. clj -Stree shows only clojure 1.11.0-alpha…. hmm… https://0bin.net/paste/QMCZRZuW#dJr0a0z7ljtw9tJY3ykONWJaSjVam87tKcJCsxWNGR8

borkdude19:11:43

did you rebuild your uberjar?

borkdude20:11:11

to be sure, do (println **clojure-version**) on the top level of your program

borkdude20:11:18

and see what it outputs during compile

genekim20:11:25

yep! Okay, will do that…

borkdude20:11:22

and then please also paste the entire output in http://0bin.net of the uberjar process + the compile output

genekim20:11:27

{:major 1, :minor 11, :incremental 0, :qualifier alpha3}

genekim20:11:38

Super cool that it’s a map, not a string.

borkdude20:11:06

There's also a function for that, which uses the map:

user=> (clojure-version)
"1.10.1"

genekim20:11:40

Will paste output when run is done in 3m. Hey, I really appreciate the help here. I can’t tell you how much it means to me!! Getting this running has been a multi-year aspiration.

borkdude20:11:40

I surely hope that this isn't a regression in clojure wrt native image ;)

borkdude20:11:51

oh god, I hope they didn't compile spec 0.3.214 using an older version of clojure

genekim20:11:26

I can’t imagine such a thing! But I’ll try using 1.10.3, just in case. Here’s the output. https://0bin.net/paste/co8gBhTX#sHKTeGkD0uSYzhhm-3VLOg6jhS4wbufY3hF5D1nLL5f

genekim20:11:09

(That’s so… novel and unexpected. 🙂). Rebuilding with older versions of clojure and spec.

borkdude20:11:33

Yeah, this instrument/unstrument stuff is still using the locking macro from clojure 1.10.1 (if it's compiled using clojure 1.10.1 which seems to be the case). https://github.com/clojure/spec.alpha/blob/a924efab53b0465f7d2a589d4ae3c79a3826403b/src/main/clojure/clojure/spec/test/alpha.clj#L363

genekim20:11:21

I can “downgrade” to spec 0.2.194, and that should/could work, yes?

borkdude20:11:57

That won't help in this case. You're just hitting these instrument/unstrument functions, which I think you shouldn't even be using in a native image.

borkdude20:11:27

I mean, they are supposed to work, but they are still using the old locking macro from 1.10.1 so that just won't work in graalvm native image.

borkdude20:11:11

So it's better to get rid of the spec instrumentation orchestra/ghostwheel stuff

genekim20:11:17

Roger that. Giving that a try!

borkdude20:11:31

nice, I made some money tonight, thank you :-D

genekim20:11:48

Wow, that was fast — I seriously thought that it would take a couple of days to process. Amazing! (I’m looking to find the way to elide ghostwheel / guardrails in production… that would be sufficient so that native-image wouldn’t see / process it, right?)

borkdude20:11:09

usually you can do this by moving all of that stuff to an isolated namespace which you don't load in production

genekim20:11:13

Hopefully last question of the day — would getting rid spec instrumentation fix this error?

Error: Detected a MBean server in the image heap. This is currently not supported, but could be changed in the future. Management beans are registered in many global caches that would need to be cleared and properly re-built at image build time. Class of disallowed object: com.sun.jmx.mbeanserver.JmxMBeanServer  To see how this object got instantiated use --trace-object-instantiation=com.sun.jmx.mbeanserver.JmxMBeanServer. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image runtime by using the option --initialize-at-run-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Trace: Object was reached by 
	reading field com.mchange.v2.c3p0.management.ActiveManagementCoordinator.mbs of
		constant com.mchange.v2.c3p0.management.ActiveManagementCoordinator@77c06e91 reached by 
	reading field 
Error: Detected a MBean server in the image heap. This is currently not supported, but could be changed in the future. Management beans are registered in many global caches that would need to be cleared and properly re-built at image build time. Class of disallowed object: com.sun.jmx.mbeanserver.JmxMBeanServer  To see how this object got instantiated use --trace-object-instantiation=com.sun.jmx.mbeanserver.JmxMBeanServer. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image runtime by using the option --initialize-at-run-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.

borkdude20:11:16

ok. if you don't have a clue why this might get initialized at build time, then try the suggested option:

--trace-object-instantiation=com.sun.jmx.mbeanserver.JmxMBeanServer
I think it's highly likely related to your server starting in the image build

genekim20:11:10

Ah. Got it. Thank you!!!

borkdude21:11:24

Oh btw, since they mention that this class may not be initialized at build time, you have to write:

--initialize-at-runtime=com.sun.jmx.mbeanserver.JmxMBeanServer
to make an exception for this class. It may still be initialized at build time, but you trace this back to where this is done and then fix it.

borkdude20:11:33
replied to a thread:After years of never quite making native images work, I’m committed to get something I run in Google Cloud Run to work. I seem to be stuck with something in `cheshire` library, I’m pretty sure that’s coming from `transit`, that’s being used by `metosin/reitit-middleware`. (Looking at `clj -Stree`.) I’m down to 3 errors — does anyone have any suggestions? (I’m 3 hours into this, and have made quite a mess. Upgrading deps, running uberjar with agents creating reflect-config.json files, ripping out cheshire for clojure.data.json, only to find out it’s still being used by reitit.) Many thanks in advance! (Full error message here: https://0bin.net/paste/AUvflgiG#PqRvpiXaTIOqR3HT5N1cW05kXeCQqGW333jf7YtCWX3. Thx to @igrishaev for teaching me about http://0bin.net. :slightly_smiling_face: Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_json_factory.invokeStatic(java.lang.Object) Parsing context: at cheshire.factory$make_json_factory.invokeStatic(factory.clj:28) at cheshire.factory$make_json_factory.invoke(factory.clj:28) at clojure.lang.MultiFn.invoke(MultiFn.java:229) at clojure.lang.AFn.applyToHelper(AFn.java:154) at clojure.lang.AFn.applyTo(AFn.java:144) at web.server.main(Unknown Source) at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147) at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183) Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_cbor_factory.invokeStatic(java.lang.Object) Parsing context: at cheshire.factory$make_cbor_factory.invokeStatic(factory.clj:84) at cheshire.factory$make_cbor_factory.invoke(factory.clj:84) at clojure.lang.MultiFn.invoke(MultiFn.java:229) at clojure.lang.AFn.applyToHelper(AFn.java:154) at clojure.lang.AFn.applyTo(AFn.java:144) at web.server.main(Unknown Source) at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147) at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183) Fatal error:com.oracle.graal.pointsto.util.AnalysisError$ParsingError: Error encountered while parsing cheshire.factory$make_smile_factory.invokeStatic(java.lang.Object) Parsing context: at cheshire.factory$make_smile_factory.invokeStatic(factory.clj:57) at cheshire.factory$make_smile_factory.invoke(factory.clj:57) at clojure.lang.MultiFn.invoke(MultiFn.java:229) at clojure.lang.AFn.applyToHelper(AFn.java:154) at clojure.lang.AFn.applyTo(AFn.java:144) at web.server.main(Unknown Source) at com.oracle.svm.core.JavaMainWrapper.runCore(JavaMainWrapper.java:147) at com.oracle.svm.core.JavaMainWrapper.run(JavaMainWrapper.java:183)

Yeah, this instrument/unstrument stuff is still using the locking macro from clojure 1.10.1 (if it's compiled using clojure 1.10.1 which seems to be the case). https://github.com/clojure/spec.alpha/blob/a924efab53b0465f7d2a589d4ae3c79a3826403b/src/main/clojure/clojure/spec/test/alpha.clj#L363

borkdude20:11:21

^ @alexmiller I think we've found an issue with clojure.spec which is related to CLJ-1472. The instrument/unstrument namespace still uses the old locking and not the locking2 . Also the new spec which is bundled with clojure 1.11-alpha3 is compiled using clojure 1.10.1. I think if you compile that with clojure 1.10.3 then you can just keep using locking and the old locking2 workaround can be removed.

Alex Miller (Clojure team)20:11:06

Can you file this somewhere? I'm on vacation :)

borkdude20:11:00

yes, I will post it on ask :) have a nice vacation :)