search

Karm / mandrel-integration-tests

Integration tests for GraalVM and its Mandrel distribution. Runs Quarkus, Helidon and Micronaut applications and small targeted reproducers. The focus is solely on native-image utility and compilation of Java applications into native executables.
Apache License 2.0
5 stars 3 forks source link

Debuginfo test fails after TrackNodeSourcePosition change (to only enable it for -O0) #131

Closed jerboaa closed 1 year ago

jerboaa commented 1 year ago

Latest graal/master fails the debuginfo test with:

2023-02-01T03:59:31.1187440Z Produced artifacts:
2023-02-01T03:59:31.1214652Z  /home/runner/work/mandrel/mandrel/mandrel-integration-tests/apps/quarkus-full-microprofile/target/quarkus-native-image-source-jar/quarkus-runner (executable)
2023-02-01T03:59:31.1215917Z  /home/runner/work/mandrel/mandrel/mandrel-integration-tests/apps/quarkus-full-microprofile/target/quarkus-native-image-source-jar/quarkus-runner-build-output-stats.json (build_info)
2023-02-01T03:59:31.1217692Z  /home/runner/work/mandrel/mandrel/mandrel-integration-tests/apps/quarkus-full-microprofile/target/quarkus-native-image-source-jar/quarkus-runner-timing-stats.json (build_info)
2023-02-01T03:59:31.1218805Z ========================================================================================================================
2023-02-01T03:59:31.1222803Z Finished generating 'quarkus-runner' in 5m 37s.
2023-02-01T03:59:31.2260324Z [INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildRunner] objcopy --strip-debug quarkus-runner
2023-02-01T03:59:31.6457188Z [INFO] [io.quarkus.deployment.QuarkusAugmentor] Quarkus augmentation completed in 343954ms
2023-02-01T03:59:31.6801169Z [INFO] ------------------------------------------------------------------------
2023-02-01T03:59:31.6814584Z [INFO] BUILD SUCCESS
2023-02-01T03:59:31.6815212Z [INFO] ------------------------------------------------------------------------
2023-02-01T03:59:31.6861342Z [INFO] Total time:  05:49 min
2023-02-01T03:59:31.6868861Z [INFO] Finished at: 2023-02-01T03:59:31Z
2023-02-01T03:59:31.6869332Z [INFO] ------------------------------------------------------------------------
2023-02-01T03:59:31.7109670Z 2023-02-01 03:59:31.709 INFO  [o.g.t.i.RuntimesSmokeTest] (testRuntime) Running...
2023-02-01T03:59:31.7617836Z 2023-02-01 03:59:31.760 INFO  [o.g.t.i.RuntimesSmokeTest] (testRuntime) Testing web page content...
2023-02-01T03:59:33.2068495Z 2023-02-01 03:59:33.205 INFO  [o.g.t.i.RuntimesSmokeTest] (testRuntime) Terminate and scan logs...
2023-02-01T03:59:33.3193861Z 2023-02-01 03:59:33.318 INFO  [o.g.t.i.RuntimesSmokeTest] (testRuntime) Gonna wait for ports closed...
2023-02-01T03:59:33.3216474Z 2023-02-01 03:59:33.320 INFO  [o.g.t.i.u.Logs] (checkLog) build-and-run.log log for quarkusFullMicroProfile contains whitelisted error: `2023-02-01 03:59:32,773 WARN  [io.jae.int.rep.RemoteReporter] (jaeger.RemoteReporter-QueueProcessor) FlushCommand execution failed! Repeated errors of this command will not be logged.: io.jaegertracing.internal.exceptions.SenderException: Failed to flush spans.'
2023-02-01T03:59:33.3224191Z 2023-02-01 03:59:33.321 INFO  [o.g.t.i.u.Logs] (checkLog) build-and-run.log log for quarkusFullMicroProfile contains whitelisted error: `2023-02-01 03:59:33,310 ERROR [io.jae.int.rep.RemoteReporter] (Thread-6) Remote reporter error [Error Occurred After Shutdown]: io.jaegertracing.internal.exceptions.SenderException: Failed to flush spans.'
2023-02-01T03:59:33.3241457Z 2023-02-01 03:59:33.323 INFO  [o.g.t.i.u.Logs] (logMeasurements) 
2023-02-01T03:59:33.3268841Z App,buildTimeMs,timeToFirstOKRequestMs,RSSKb,executableSizeKb,FDs
2023-02-01T03:59:33.3269858Z QUARKUS_FULL_MICROPROFILE,350300,48,82712,70434,26
2023-02-01T03:59:33.3692175Z [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 527.268 s - in org.graalvm.tests.integration.RuntimesSmokeTest
2023-02-01T03:59:33.7464040Z [INFO] 
2023-02-01T03:59:33.7464745Z [INFO] Results:
2023-02-01T03:59:33.7465502Z [INFO] 
2023-02-01T03:59:33.7467770Z [ERROR] Failures: 
2023-02-01T03:59:33.7479481Z [ERROR]   DebugSymbolsTest.debugSymbolsQuarkus:213->carryOutGDBSession:378 There were errors in the GDB session. Note that commands in the session might depend on each other. Errors: 
2023-02-01T03:59:33.7480380Z Command 'b ConfigTestController.java:33' did not match the expected pattern '.*Breakpoint 1 at .*: file com/example/quarkus/config/ConfigTestController.java, line 33.*'.
2023-02-01T03:59:33.7480927Z Output was:
2023-02-01T03:59:33.7481336Z (gdb) (gdb) (gdb) GNU gdb (Ubuntu 12.1-0ubuntu1~22.04) 12.1
2023-02-01T03:59:33.7481719Z Copyright (C) 2022 Free Software Foundation, Inc.
2023-02-01T03:59:33.7482107Z License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
2023-02-01T03:59:33.7482545Z This is free software: you are free to change and redistribute it.
2023-02-01T03:59:33.7482935Z There is NO WARRANTY, to the extent permitted by law.
2023-02-01T03:59:33.7483313Z Type "show copying" and "show warranty" for details.
2023-02-01T03:59:33.7483692Z This GDB was configured as "x86_64-linux-gnu".
2023-02-01T03:59:33.7484066Z Type "show configuration" for configuration details.
2023-02-01T03:59:33.7484436Z For bug reporting instructions, please see:
2023-02-01T03:59:33.7484885Z <https://www.gnu.org/software/gdb/bugs/>.
2023-02-01T03:59:33.7485923Z Find the GDB manual and other documentation resources online at:
2023-02-01T03:59:33.7486591Z     <http://www.gnu.org/software/gdb/documentation/>.
2023-02-01T03:59:33.7486812Z 
2023-02-01T03:59:33.7486888Z For help, type "help".
2023-02-01T03:59:33.7487240Z Type "apropos word" to search for commands related to "word".
2023-02-01T03:59:33.7487629Z (gdb) No symbol table is loaded.  Use the "file" command.
2023-02-01T03:59:33.7487936Z , 
2023-02-01T03:59:33.7488431Z Command 'bt' did not match the expected pattern '.*at.*com/example/quarkus/config/ConfigTestController.java:33.*'.
2023-02-01T03:59:33.7488844Z Output was:
2023-02-01T03:59:33.7489126Z Selected thread is running.
2023-02-01T03:59:33.7489404Z (gdb) [New Thread 0x7fffd2ffe640 (LWP 4342)]
2023-02-01T03:59:33.7489821Z [New Thread 0x7fffd1ffd640 (LWP 4343)]
2023-02-01T03:59:33.7490154Z [New Thread 0x7fffcbfff640 (LWP 4344)]
2023-02-01T03:59:33.7490559Z [New Thread 0x7fffcaffe640 (LWP 4345)]
2023-02-01T03:59:33.7495319Z 2023-02-01 03:34:05,083 WARN  [io.jae.int.rep.RemoteReporter] (jaeger.RemoteReporter-QueueProcessor) FlushCommand execution failed! Repeated errors of this command will not be logged.: io.jaegertracing.internal.exceptions.SenderException: Failed to flush spans.
2023-02-01T03:59:33.7496303Z    at io.jaegertracing.thrift.internal.senders.ThriftSender.flush(ThriftSender.java:116)
2023-02-01T03:59:33.7496953Z    at io.jaegertracing.internal.reporters.RemoteReporter$FlushCommand.execute(RemoteReporter.java:158)
2023-02-01T03:59:33.7497633Z    at io.jaegertracing.internal.reporters.RemoteReporter$QueueProcessor.run(RemoteReporter.java:179)
2023-02-01T03:59:33.7498256Z    at java.base@17.0.6-beta/java.lang.Thread.run(Thread.java:833)
2023-02-01T03:59:33.7498875Z    at org.graalvm.nativeimage.builder/com.oracle.svm.core.thread.PlatformThreads.threadStartRoutine(PlatformThreads.java:800)
2023-02-01T03:59:33.7499810Z    at org.graalvm.nativeimage.builder/com.oracle.svm.core.posix.thread.PosixPlatformThreads.pthreadStartRoutine(PosixPlatformThreads.java:211)
2023-02-01T03:59:33.7500684Z Caused by: io.jaegertracing.internal.exceptions.SenderException: Could not send 1 spans
2023-02-01T03:59:33.7501276Z    at io.jaegertracing.thrift.internal.senders.HttpSender.send(HttpSender.java:70)
2023-02-01T03:59:33.7501885Z    at io.jaegertracing.thrift.internal.senders.ThriftSender.flush(ThriftSender.java:114)
2023-02-01T03:59:33.7502394Z    ... 5 more
2023-02-01T03:59:33.7502719Z Caused by: java.net.ConnectException: Failed to connect to localhost/[0:0:0:0:0:0:0:1]:14268
2023-02-01T03:59:33.7503263Z    at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:265)
2023-02-01T03:59:33.7503842Z    at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:183)
2023-02-01T03:59:33.7504452Z    at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.java:224)
2023-02-01T03:59:33.7505100Z    at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.java:108)
2023-02-01T03:59:33.7505717Z    at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.java:88)
2023-02-01T03:59:33.7506272Z    at okhttp3.internal.connection.Transmitter.newExchange(Transmitter.java:169)
2023-02-01T03:59:33.7506811Z    at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:41)
2023-02-01T03:59:33.7507422Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2023-02-01T03:59:33.7508016Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2023-02-01T03:59:33.7508612Z    at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:94)
2023-02-01T03:59:33.7509198Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2023-02-01T03:59:33.7509783Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2023-02-01T03:59:33.7510424Z    at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
2023-02-01T03:59:33.7510959Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2023-02-01T03:59:33.7511843Z    at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:88)
2023-02-01T03:59:33.7512571Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
2023-02-01T03:59:33.7513110Z    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
2023-02-01T03:59:33.7513694Z    at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:229)
2023-02-01T03:59:33.7514148Z    at okhttp3.RealCall.execute(RealCall.java:81)
2023-02-01T03:59:33.7514638Z    at io.jaegertracing.thrift.internal.senders.HttpSender.send(HttpSender.java:68)
2023-02-01T03:59:33.7515086Z    ... 6 more
2023-02-01T03:59:33.7515428Z Caused by: java.net.ConnectException: Connection refused
2023-02-01T03:59:33.7515931Z    at java.base@17.0.6-beta/sun.nio.ch.Net.pollConnect(Net.java)
2023-02-01T03:59:33.7516484Z    at java.base@17.0.6-beta/sun.nio.ch.Net.pollConnectNow(Net.java:672)
2023-02-01T03:59:33.7517172Z    at java.base@17.0.6-beta/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
2023-02-01T03:59:33.7517795Z    at java.base@17.0.6-beta/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
2023-02-01T03:59:33.7518468Z    at java.base@17.0.6-beta/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
2023-02-01T03:59:33.7519008Z    at java.base@17.0.6-beta/java.net.Socket.connect(Socket.java:633)
2023-02-01T03:59:33.7519490Z    at okhttp3.internal.platform.Platform.connectSocket(Platform.java:130)
2023-02-01T03:59:33.7520062Z    at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:263)
2023-02-01T03:59:33.7520438Z    ... 25 more
2023-02-01T03:59:33.7520595Z 
2023-02-01T03:59:33.7520699Z , 
2023-02-01T03:59:33.7521298Z Command 'list' did not match the expected pattern '.*String value = config.getValue\("value", String.class\);.*'.
2023-02-01T03:59:33.7521645Z Output was:
2023-02-01T03:59:33.7522028Z 1  ../sysdeps/x86/abi-note.c: No such file or directory.
2023-02-01T03:59:33.7522329Z , 
2023-02-01T03:59:33.7522671Z Command 'c&' did not match the expected pattern '.*Continuing.*'.
2023-02-01T03:59:33.7523007Z Output was:
2023-02-01T03:59:33.7523352Z (gdb) Cannot execute this command while the selected thread is running.
2023-02-01T03:59:33.7523665Z  ==> expected: <true> but was: <false>
2023-02-01T03:59:33.7524411Z [ERROR]   DebugSymbolsTest.debugSymbolsSmokeGDB:137->carryOutGDBSession:378 There were errors in the GDB session. Note that commands in the session might depend on each other. Errors: 
2023-02-01T03:59:33.7525204Z Command 'break Main.java:71' did not match the expected pattern '.*Breakpoint 2 at .*: file debug_symbols_smoke/Main.java, line 71.*'.
2023-02-01T03:59:33.7525614Z Output was:
2023-02-01T03:59:33.7525920Z (gdb) Breakpoint 2 at 0x55555568a5e0: file debug_symbols_smoke/Main.java, line 72.
2023-02-01T03:59:33.7526255Z , 
2023-02-01T03:59:33.7565820Z Command 'c' did not match the expected pattern '.*Breakpoint 2, debug_symbols_smoke.Main::main.*at debug_symbols_smoke/Main.java:71.* if \(myString != null.*'.
2023-02-01T03:59:33.7566664Z Output was:
2023-02-01T03:59:33.7566897Z (gdb) Continuing.
2023-02-01T03:59:33.7567063Z 
2023-02-01T03:59:33.7568036Z Thread 1 "debug-symbols-s" hit Breakpoint 2, debug_symbols_smoke.Main::main(java.lang.String[]*) (args=<optimized out>) at debug_symbols_smoke/Main.java:72
2023-02-01T03:59:33.7568569Z 72                     ays.add(new ClassA(myNumber, myString));
2023-02-01T03:59:33.7568824Z , 
2023-02-01T03:59:33.7570830Z Command 'c' did not match the expected pattern '.*Breakpoint 2, debug_symbols_smoke.Main::main.*at debug_symbols_smoke/Main.java:71.* if \(myString != null.*'.
2023-02-01T03:59:33.7571309Z Output was:
2023-02-01T03:59:33.7571580Z (gdb) Continuing.
2023-02-01T03:59:33.7571694Z 
2023-02-01T03:59:33.7572248Z Thread 1 "debug-symbols-s" hit Breakpoint 2, debug_symbols_smoke.Main::main(java.lang.String[]*) (args=<optimized out>) at debug_symbols_smoke/Main.java:72
2023-02-01T03:59:33.7575369Z 72                     ays.add(new ClassA(myNumber, myString));
2023-02-01T03:59:33.7575942Z  ==> expected: <true> but was: <false>
2023-02-01T03:59:33.7576926Z [INFO] 
2023-02-01T03:59:33.7577260Z [ERROR] Tests run: 18, Failures: 2, Errors: 0, Skipped: 5

The graalvm change which introduced this was: https://github.com/oracle/graal/commit/67cc5c201bcbef1d4abe02c966fdd1c35fc583c2

jerboaa commented 1 year ago

Example failure here: https://github.com/Karm/mandrel-integration-tests/issues/102#issuecomment-1411445678 https://github.com/graalvm/mandrel/actions/runs/4060214227

zakkak commented 1 year ago

Thanks for creating this @jerboaa , I created https://github.com/quarkusio/quarkus/issues/30772 on the Quarkus repo as well, since we need to handle this there as well.

jerboaa commented 1 year ago

@zakkak Do you know if the graal vm change is permanent and we ought to fix it with a quarkus PR? I'm worried we might miss other failures due to this. Thanks!