[2025-10-17T20:30:02.226Z] Running test renaissance-finagle-http_0 ... [2025-10-17T20:30:02.226Z] =============================================== [2025-10-17T20:30:02.226Z] renaissance-finagle-http_0 Start Time: Fri Oct 17 20:30:01 2025 Epoch Time (ms): 1760733001333 [2025-10-17T20:30:02.226Z] variation: NoOptions [2025-10-17T20:30:02.226Z] JVM_OPTIONS: [2025-10-17T20:30:02.226Z] { \ [2025-10-17T20:30:02.226Z] echo ""; echo "TEST SETUP:"; \ [2025-10-17T20:30:02.226Z] echo "Nothing to be done for setup."; \ [2025-10-17T20:30:02.226Z] mkdir -p "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../TKG/output_17607330005203/renaissance-finagle-http_0"; \ [2025-10-17T20:30:02.226Z] cd "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../TKG/output_17607330005203/renaissance-finagle-http_0"; \ [2025-10-17T20:30:02.226Z] echo ""; echo "TESTING:"; \ [2025-10-17T20:30:02.226Z] "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/jdkbinary/j2sdk-image/bin/java" --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.nio=ALL-UNNAMED --add-opens java.base/sun.nio.ch=ALL-UNNAMED --add-opens java.base/java.lang.invoke=ALL-UNNAMED -jar "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../../jvmtest/perf/renaissance/renaissance.jar" --json ""/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../TKG/output_17607330005203/renaissance-finagle-http_0"/finagle-http.json" finagle-http; \ [2025-10-17T20:30:02.226Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "renaissance-finagle-http_0""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/..; rm -f -r "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../TKG/output_17607330005203/renaissance-finagle-http_0"; else echo "-----------------------------------"; echo "renaissance-finagle-http_0""_FAILED"; echo "-----------------------------------"; fi; \ [2025-10-17T20:30:02.226Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-10-17T20:30:02.226Z] echo "Nothing to be done for teardown."; \ [2025-10-17T20:30:02.226Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/../TKG/output_17607330005203/TestTargetResult"; [2025-10-17T20:30:02.226Z] [2025-10-17T20:30:02.226Z] TEST SETUP: [2025-10-17T20:30:02.226Z] Nothing to be done for setup. [2025-10-17T20:30:02.226Z] [2025-10-17T20:30:02.226Z] TESTING: [2025-10-17T20:30:04.211Z] WARNING: A terminally deprecated method in sun.misc.Unsafe has been called [2025-10-17T20:30:04.211Z] WARNING: sun.misc.Unsafe::objectFieldOffset has been called by scala.runtime.LazyVals$ (file:/home/jenkins/workspace/Test_openjdk25_hs_extended.perf_riscv64_linux_testList_0/aqa-tests/TKG/output_17607330005203/renaissance-finagle-http_0/launcher-203002-5059525266413779258/renaissance-harness_3/lib/scala3-library_3-3.3.4.jar) [2025-10-17T20:30:04.211Z] WARNING: Please consider reporting this to the maintainers of class scala.runtime.LazyVals$ [2025-10-17T20:30:04.211Z] WARNING: sun.misc.Unsafe::objectFieldOffset will be removed in a future release [2025-10-17T20:30:17.307Z] finagle-http on :34457 spawning 4 client and default number of server workers. [2025-10-17T20:30:17.308Z] ====== finagle-http (web) [default], iteration 0 started ====== [2025-10-17T20:30:17.308Z] GC before operation: completed in 142.811 ms, heap usage 17.788 MB -> 11.003 MB. [2025-10-17T20:31:55.500Z] [2025-10-17T20:31:41.943+0000] monitor (com.twitter.util.RootMonitor$$anonfun$2 applyOrElse) [2025-10-17T20:31:55.500Z] SEVERE: Exception propagated to the root monitor! [2025-10-17T20:31:55.500Z] [2025-10-17T20:31:55.500Z] java.lang.IllegalMonitorStateException: attempt to unlock read lock, not locked by current thread [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.locks.ReentrantReadWriteLock$Sync.unmatchedUnlockException(ReentrantReadWriteLock.java:452) [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryReleaseShared(ReentrantReadWriteLock.java:436) [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.locks.AbstractQueuedLongSynchronizer.releaseShared(AbstractQueuedLongSynchronizer.java:806) [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.unlock(ReentrantReadWriteLock.java:903) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.Closables.register(Closables.scala:49) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.ListeningStackServer$$anon$1.$anonfun$underlying$1(ListeningStackServer.scala:110) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.ListeningStackServer$$anon$1.$anonfun$underlying$1$adapted(ListeningStackServer.scala:108) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.StdStackServer.mkSession$1(StdStackServer.scala:97) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.StdStackServer.$anonfun$newListeningServer$3(StdStackServer.scala:103) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.StdStackServer.$anonfun$newListeningServer$3$adapted(StdStackServer.scala:101) [2025-10-17T20:31:55.500Z] at com.twitter.util.ConstFuture.com$twitter$util$ConstFuture$$$anonfun$respond$1(ConstFuture.scala:30) [2025-10-17T20:31:55.500Z] at com.twitter.util.ConstFuture$$anonfun$respond$2.doRun(ConstFuture.scala:21) [2025-10-17T20:31:55.500Z] at com.twitter.util.FiberTask.run(FiberTask.scala:14) [2025-10-17T20:31:55.500Z] at com.twitter.concurrent.LocalScheduler$Activation.run(Scheduler.scala:167) [2025-10-17T20:31:55.500Z] at com.twitter.concurrent.LocalScheduler$Activation.submit(Scheduler.scala:126) [2025-10-17T20:31:55.500Z] at com.twitter.concurrent.LocalScheduler.submit(Scheduler.scala:243) [2025-10-17T20:31:55.500Z] at com.twitter.concurrent.Scheduler$.submit(Scheduler.scala:78) [2025-10-17T20:31:55.500Z] at com.twitter.util.Fiber$$anon$1.submitTask(Fiber.scala:22) [2025-10-17T20:31:55.500Z] at com.twitter.util.ConstFuture.respond(ConstFuture.scala:21) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.StdStackServer.$anonfun$newListeningServer$1(StdStackServer.scala:101) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.server.StdStackServer.$anonfun$newListeningServer$1$adapted(StdStackServer.scala:83) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.netty4.channel.ServerBridge.channelActive(ServerBridge.scala:21) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:260) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:238) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:231) [2025-10-17T20:31:55.500Z] at io.netty.channel.DefaultChannelPipeline$HeadContext.channelActive(DefaultChannelPipeline.java:1345) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:258) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:238) [2025-10-17T20:31:55.500Z] at io.netty.channel.DefaultChannelPipeline.fireChannelActive(DefaultChannelPipeline.java:844) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.AbstractHttp2StreamChannel$Http2ChannelUnsafe.register(AbstractHttp2StreamChannel.java:686) [2025-10-17T20:31:55.500Z] at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:89) [2025-10-17T20:31:55.500Z] at io.netty.channel.SingleThreadEventLoop.register(SingleThreadEventLoop.java:83) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2MultiplexHandler.userEventTriggered(Http2MultiplexHandler.java:252) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:398) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:376) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.fireUserEventTriggered(AbstractChannelHandlerContext.java:368) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2FrameCodec.onHttp2StreamStateChanged(Http2FrameCodec.java:713) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2FrameCodec.onStreamActive0(Http2FrameCodec.java:503) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2FrameCodec.access$700(Http2FrameCodec.java:146) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2FrameCodec$ConnectionListener.onStreamActive(Http2FrameCodec.java:518) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.addToActiveStreams(DefaultHttp2Connection.java:1022) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2Connection$ActiveStreams.activate(DefaultHttp2Connection.java:977) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultStream.activate(DefaultHttp2Connection.java:504) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultEndpoint.createStream(DefaultHttp2Connection.java:781) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2Connection$DefaultEndpoint.createStream(DefaultHttp2Connection.java:685) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:360) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder$FrameReadListener.onHeadersRead(DefaultHttp2ConnectionDecoder.java:350) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2FrameReader$2.processFragment(DefaultHttp2FrameReader.java:475) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readHeadersFrame(DefaultHttp2FrameReader.java:483) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2FrameReader.processPayloadState(DefaultHttp2FrameReader.java:247) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2FrameReader.readFrame(DefaultHttp2FrameReader.java:164) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DefaultHttp2ConnectionDecoder.decodeFrame(DefaultHttp2ConnectionDecoder.java:186) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DecoratingHttp2ConnectionDecoder.decodeFrame(DecoratingHttp2ConnectionDecoder.java:61) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.DecoratingHttp2ConnectionDecoder.decodeFrame(DecoratingHttp2ConnectionDecoder.java:61) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2ConnectionHandler$FrameDecoder.decode(Http2ConnectionHandler.java:391) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.http2.Http2ConnectionHandler.decode(Http2ConnectionHandler.java:451) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469) [2025-10-17T20:31:55.500Z] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [2025-10-17T20:31:55.500Z] at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1357) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) [2025-10-17T20:31:55.500Z] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [2025-10-17T20:31:55.500Z] at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:868) [2025-10-17T20:31:55.500Z] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [2025-10-17T20:31:55.500Z] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) [2025-10-17T20:31:55.500Z] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) [2025-10-17T20:31:55.500Z] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) [2025-10-17T20:31:55.500Z] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) [2025-10-17T20:31:55.500Z] at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) [2025-10-17T20:31:55.500Z] at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1090) [2025-10-17T20:31:55.500Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:614) [2025-10-17T20:31:55.500Z] at com.twitter.finagle.util.BlockingTimeTrackingThreadFactory$$anon$1.run(BlockingTimeTrackingThreadFactory.scala:23) [2025-10-17T20:31:55.500Z] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [2025-10-17T20:31:55.500Z] at java.base/java.lang.Thread.run(Thread.java:1474) [2025-10-17T20:31:56.676Z] ====== finagle-http (web) [default], iteration 0 completed (100908.607 ms) ====== [2025-10-17T20:31:56.676Z] ====== finagle-http (web) [default], iteration 1 started ====== [2025-10-17T20:31:57.009Z] GC before operation: completed in 510.529 ms, heap usage 47.058 MB -> 14.791 MB. [2025-10-17T20:32:54.753Z] ====== finagle-http (web) [default], iteration 1 completed (50030.371 ms) ====== [2025-10-17T20:32:54.753Z] ====== finagle-http (web) [default], iteration 2 started ====== [2025-10-17T20:32:54.753Z] GC before operation: completed in 425.462 ms, heap usage 31.523 MB -> 14.615 MB. [2025-10-17T20:33:22.486Z] ====== finagle-http (web) [default], iteration 2 completed (31242.129 ms) ====== [2025-10-17T20:33:22.486Z] ====== finagle-http (web) [default], iteration 3 started ====== [2025-10-17T20:33:22.486Z] GC before operation: completed in 372.483 ms, heap usage 41.300 MB -> 14.649 MB. [2025-10-17T20:33:50.216Z] ====== finagle-http (web) [default], iteration 3 completed (29928.800 ms) ====== [2025-10-17T20:33:50.216Z] ====== finagle-http (web) [default], iteration 4 started ====== [2025-10-17T20:33:50.216Z] GC before operation: completed in 371.504 ms, heap usage 83.266 MB -> 15.416 MB. [2025-10-17T20:34:23.575Z] ====== finagle-http (web) [default], iteration 4 completed (31052.708 ms) ====== [2025-10-17T20:34:23.575Z] ====== finagle-http (web) [default], iteration 5 started ====== [2025-10-17T20:34:23.575Z] GC before operation: completed in 362.604 ms, heap usage 79.391 MB -> 14.617 MB. [2025-10-17T20:34:56.932Z] ====== finagle-http (web) [default], iteration 5 completed (30793.491 ms) ====== [2025-10-17T20:34:56.932Z] ====== finagle-http (web) [default], iteration 6 started ====== [2025-10-17T20:34:56.932Z] GC before operation: completed in 359.276 ms, heap usage 69.251 MB -> 14.685 MB. [2025-10-17T20:35:24.702Z] ====== finagle-http (web) [default], iteration 6 completed (30545.469 ms) ====== [2025-10-17T20:35:24.702Z] ====== finagle-http (web) [default], iteration 7 started ====== [2025-10-17T20:35:24.702Z] GC before operation: completed in 368.406 ms, heap usage 102.280 MB -> 14.614 MB. [2025-10-17T20:35:58.128Z] ====== finagle-http (web) [default], iteration 7 completed (30440.680 ms) ====== [2025-10-17T20:35:58.128Z] ====== finagle-http (web) [default], iteration 8 started ====== [2025-10-17T20:35:58.128Z] GC before operation: completed in 383.988 ms, heap usage 51.842 MB -> 14.656 MB. [2025-10-17T20:36:27.283Z] ====== finagle-http (web) [default], iteration 8 completed (32303.392 ms) ====== [2025-10-17T20:36:27.283Z] ====== finagle-http (web) [default], iteration 9 started ====== [2025-10-17T20:36:27.283Z] GC before operation: completed in 398.765 ms, heap usage 46.157 MB -> 14.828 MB. [2025-10-17T20:37:00.641Z] ====== finagle-http (web) [default], iteration 9 completed (31701.019 ms) ====== [2025-10-17T20:37:00.641Z] ====== finagle-http (web) [default], iteration 10 started ====== [2025-10-17T20:37:00.641Z] GC before operation: completed in 383.530 ms, heap usage 93.412 MB -> 14.663 MB. [2025-10-17T20:37:34.013Z] ====== finagle-http (web) [default], iteration 10 completed (31051.231 ms) ====== [2025-10-17T20:37:34.013Z] ====== finagle-http (web) [default], iteration 11 started ====== [2025-10-17T20:37:34.013Z] GC before operation: completed in 379.996 ms, heap usage 94.404 MB -> 14.651 MB. [2025-10-18T21:23:49.863Z] Cancelling nested steps due to timeout [2025-10-18T21:23:49.893Z] Sending interrupt signal to process [2025-10-18T21:23:53.215Z] ----------------------------------- [2025-10-18T21:23:53.215Z] renaissance-finagle-http_0_FAILED [2025-10-18T21:23:53.215Z] ----------------------------------- [2025-10-18T21:23:53.215Z] [2025-10-18T21:23:53.215Z] TEST TEARDOWN: [2025-10-18T21:23:53.215Z] Nothing to be done for teardown. [2025-10-18T21:23:53.215Z] renaissance-finagle-http_0 Finish Time: Sat Oct 18 21:23:51 2025 Epoch Time (ms): 1760822631272