graal icon indicating copy to clipboard operation
graal copied to clipboard

[native-image] started threads at image build time - any better diagnostic methods?

Open aclement opened this issue 5 years ago • 11 comments

I've got my spring apps working well with netty, now turning to tomcat. I've progressed a lot but hit this now and am having a little trouble diagnosing:


Error: Detected a started Thread in the image heap. Threads running in the image generator are no longer running at image run time. Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Trace: 	object java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue
	object java.util.concurrent.ScheduledThreadPoolExecutor
	method sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease)
Call path from entry point to sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease):
	at sun.rmi.transport.DGCImpl.dirty(DGCImpl.java:168)
	at sun.rmi.transport.DGCClient$EndpointEntry.makeDirtyCall(DGCClient.java:382)
	at sun.rmi.transport.DGCClient$EndpointEntry.access$1600(DGCClient.java:192)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:606)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:603)
	at com.oracle.svm.core.jdk.Target_java_security_AccessController.doPrivileged(SecuritySubstitutions.java:79)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:603)
	at java.lang.Thread.run(Thread.java:748)
	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
	at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)

This happens when I call native-image for my basic spring app with the spring-graal-feature included. Firstly the error message reads a bit odd:

You can request class initialization at image run time by using the option --initialize-at-build-time=

Shouldn't that say '--initialize-at-run-time' as the option?

But ignoring that I don't have a lot to go on - I've no doubt the message is true but the stacks and trace aren't useful to me really.

Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked.

This suggests there is something I can do, but not 100% on what that is, is it supplying the native-image-agent to the native-image call? Any docs on how to do that? I didn't see any options to enable it, I can't use -agentlib as unsupported by native-image. I can't use -Jagentlib:... - seems to give me a noclassdeffounderror for TransformerInterface

Any tips or pointers? Many thanks!

aclement avatar Sep 09 '19 19:09 aclement

Thanks for reporting, I will fix the error message and also it would be very useful to have the binaries to see why the instrumentation did not fire.

In the meanwhile, you can do the old trick of using --debug-attach putting a breakpoint to the place where this field is written or to the Thread constructor and see how this got initialized. Then you need to --initialize-at-run-time the cause of this initialization.

vjovanov avatar Sep 10 '19 10:09 vjovanov

I'll put together the repro case. I thought I did try --debug-attach but it didn't get me what I wanted, I'll double check that.

aclement avatar Sep 11 '19 00:09 aclement

The spring-boot-graal-feature has now moved to https://github.com/spring-projects-experimental/spring-graal-feature - if you clone that, then mvn package the top level project, then go into samples/tomcat and run compile.sh it will build the sample with maven then call native-image on it (Graal 19.2)

For me that produces this kind of thing - maybe the stacks just aren't long enough but I'm not finding quite enough for me to go on:


Error: Unsupported features in 4 methods
Detailed message:
Error: Detected a started Thread in the image heap. Threads running in the image generator are no longer running at image run time. Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Trace: 	object java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue
	object java.util.concurrent.ScheduledThreadPoolExecutor
	method sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease)
Call path from entry point to sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease): 
	at sun.rmi.transport.DGCImpl.dirty(DGCImpl.java:168)
	at sun.rmi.transport.DGCClient$EndpointEntry.makeDirtyCall(DGCClient.java:382)
	at sun.rmi.transport.DGCClient$EndpointEntry.access$1600(DGCClient.java:192)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:606)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:603)
	at com.oracle.svm.core.jdk.Target_java_security_AccessController.doPrivileged(SecuritySubstitutions.java:79)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:603)
	at java.lang.Thread.run(Thread.java:748)
	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
	at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)
Error: Detected a started Thread in the image heap. Threads running in the image generator are no longer running at image run time. Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Trace: 	object java.util.concurrent.ThreadPoolExecutor$Worker
	object java.util.HashMap$Node
	object java.util.HashMap$Node[]
	object java.util.HashMap
	object java.util.HashSet
	object java.util.concurrent.ScheduledThreadPoolExecutor
	method sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease)
Call path from entry point to sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease): 
	at sun.rmi.transport.DGCImpl.dirty(DGCImpl.java:168)
	at sun.rmi.transport.DGCClient$EndpointEntry.makeDirtyCall(DGCClient.java:382)
	at sun.rmi.transport.DGCClient$EndpointEntry.access$1600(DGCClient.java:192)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:606)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:603)
	at com.oracle.svm.core.jdk.Target_java_security_AccessController.doPrivileged(SecuritySubstitutions.java:79)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:603)
	at java.lang.Thread.run(Thread.java:748)
	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
	at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)
Error: Detected a started Thread in the image heap. Threads running in the image generator are no longer running at image run time. Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked. The object was probably created by a class initializer and is reachable from a static field. You can request class initialization at image run time by using the option --initialize-at-build-time=<class-name>. Or you can write your own initialization methods and call them explicitly from your main entry point.
Trace: 	object java.util.concurrent.locks.AbstractQueuedSynchronizer$Node
	object java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
	object java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue
	object java.util.concurrent.ScheduledThreadPoolExecutor
	method sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease)
Call path from entry point to sun.rmi.transport.DGCImpl.dirty(ObjID[], long, Lease): 
	at sun.rmi.transport.DGCImpl.dirty(DGCImpl.java:168)
	at sun.rmi.transport.DGCClient$EndpointEntry.makeDirtyCall(DGCClient.java:382)
	at sun.rmi.transport.DGCClient$EndpointEntry.access$1600(DGCClient.java:192)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:606)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread$1.run(DGCClient.java:603)
	at com.oracle.svm.core.jdk.Target_java_security_AccessController.doPrivileged(SecuritySubstitutions.java:79)
	at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:603)
	at java.lang.Thread.run(Thread.java:748)
	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
	at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)
Error: No instances of java.net.SocksSocketImpl are allowed in the image heap as this class should be initialized at image runtime.Object has been initialized without the native-image initialization instrumentation and the stack trace can't be tracked.
Trace: 	object sun.management.jmxremote.LocalRMIServerSocketFactory$1
	object sun.rmi.transport.tcp.TCPTransport
	object sun.rmi.transport.tcp.TCPEndpoint
	object java.util.LinkedList$Node
	object java.util.LinkedList
	object java.util.HashMap$Node
	object java.util.HashMap$Node[]
	object java.util.HashMap
	method sun.rmi.transport.tcp.TCPEndpoint.setLocalHost(String)
Call path from entry point to sun.rmi.transport.tcp.TCPEndpoint.setLocalHost(String): 
	at sun.rmi.transport.tcp.TCPEndpoint.setLocalHost(TCPEndpoint.java:291)
	at sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:263)
	at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:202)
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:129)
	at javax.management.remote.rmi.RMIConnectionImpl_Stub.close(Unknown Source)
	at com.oracle.svm.reflect.AutoCloseable_close_5d5fee5826f99c7862638153e584ef1e7b2ab93f_5461.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at javax.xml.transform.TransformerException.printStackTrace(TransformerException.java:348)
	at javax.xml.transform.TransformerException.printStackTrace(TransformerException.java:282)
	at com.oracle.svm.jni.functions.JNIFunctions.ExceptionDescribe(JNIFunctions.java:761)
	at com.oracle.svm.core.code.IsolateEnterStub.JNIFunctions_ExceptionDescribe_b5412f7570bccae90b000bc37855f00408b2ad73(generated:0)

I have been playing with debug-attach but the breakpoints in thread trigger without showing me how it got there, tricky. Still playing.

aclement avatar Sep 11 '19 15:09 aclement

In the meanwhile, you can do the old trick of using --debug-attach...

I'm kind of joining late in the game, so the "old tricks" are new to me.

Is --debug-attach an mx thing? Should I be using native-image from mx?

MaggieLeber avatar Sep 19 '19 18:09 MaggieLeber

Nope, it is a native-image thing. No need for mx, you can use the distributed version as long as your IDE knows where the sources are.

If that is hard to set up, you can build GraalVM and setup your IDE with mx.

vjovanov avatar Sep 19 '19 18:09 vjovanov

Thanks...I'd looked at thenative-image --help and didn't see it; I should have looked at the actual manual. :-)

MaggieLeber avatar Sep 19 '19 18:09 MaggieLeber

Yes, this option is not really for end-users as it requires source code.

vjovanov avatar Sep 20 '19 06:09 vjovanov

I'd looked at the native-image --help and didn't see it;

> native-image --help
GraalVM native-image building tool
...
    --help-extra          print help on non-standard options
...

> native-image --help-extra
Non-standard options help:
...
    --debug-attach[=<port>]
                          attach to debugger during image building (default port is 8000)
...

olpaw avatar Sep 20 '19 06:09 olpaw

I'm such a noob. Thanks, @olpaw

MaggieLeber avatar Sep 20 '19 11:09 MaggieLeber

you can use the distributed version as long as your IDE knows where the sources are.

I have installed native-image using gu install native-image and I've cloned this repo and am debugging by using --debug-attach. I'm able to stop on a break point so i know it's all working well. the only thing is, I want to make sure that have the exact version of graal/substratevm that is that which was used to build the native-image that I'm using.. is there a way to get it's tag or commit sha so that I may checkout the corresponding version?

rickmarry avatar Jul 12 '22 14:07 rickmarry

is there a way to get it's tag

I got it.. I just had to get the native-image version by running: native-image --version then I checked out the matching tag that correlated with that version. So in my case native-image --version returned: GraalVM 22.1.0 Java 11 CE (Java Version 11.0.15+10-jvmci-22.1-b06). Then on this repo, I then checked out tag: vm-22.1.0 as that's what matches the version on Graal.. now when I debug, the break point lines are consistent.

rickmarry avatar Jul 12 '22 15:07 rickmarry

I am closing this older ticket, a lot has changed in Native Image, especially around class initialization, so I assume this is not longer a problem with the latest versions.

If you still experience this problem, please file a new ticket, ideally with a reproducer that we can debug on our side.

wirthi avatar Jan 24 '24 11:01 wirthi