[2024-08-01T00:04:10.618Z] Running test jdk_net_1 ... [2024-08-01T00:04:10.618Z] =============================================== [2024-08-01T00:04:11.227Z] jdk_net_1 Start Time: Thu Aug 1 00:04:10 2024 Epoch Time (ms): 1722470650622 [2024-08-01T00:04:11.227Z] variation: Mode650 [2024-08-01T00:04:11.227Z] JVM_OPTIONS: -XX:-UseCompressedOops [2024-08-01T00:04:11.227Z] { \ [2024-08-01T00:04:11.227Z] echo ""; echo "TEST SETUP:"; \ [2024-08-01T00:04:11.227Z] echo "Nothing to be done for setup."; \ [2024-08-01T00:04:11.227Z] mkdir -p "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1"; \ [2024-08-01T00:04:11.227Z] cd "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1"; \ [2024-08-01T00:04:11.227Z] echo ""; echo "TESTING:"; \ [2024-08-01T00:04:11.227Z] "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/java" -Xmx512m -jar "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../../jvmtest/openjdk/jtreg/lib/jtreg.jar" \ [2024-08-01T00:04:11.227Z] -agentvm -a -ea -esa -v:fail,error,time,nopass -retain:fail,error,*.dmp,javacore.*,heapdump.*,*.trc -ignore:quiet -timeoutFactor:16 -xml:verify -k:'!headful' -concurrency:3 -nativepath:"/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native" -vmoptions:"-Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true" \ [2024-08-01T00:04:11.227Z] -w ""/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1"/work" \ [2024-08-01T00:04:11.227Z] -r ""/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1"/report" \ [2024-08-01T00:04:11.227Z] -jdk:"/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image" \ [2024-08-01T00:04:11.227Z] -exclude:"/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk/ProblemList.txt" \ [2024-08-01T00:04:11.227Z] -exclude:"/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../../jvmtest/openjdk/excludes/ProblemList_openjdk21.txt" \ [2024-08-01T00:04:11.227Z] \ [2024-08-01T00:04:11.227Z] -exclude:"/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../openjdk/excludes/vendors/eclipse/ProblemList_openjdk21.txt" \ [2024-08-01T00:04:11.227Z] "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk:jdk_net"; \ [2024-08-01T00:04:11.227Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "jdk_net_1""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/..; else echo "-----------------------------------"; echo "jdk_net_1""_FAILED"; echo "-----------------------------------"; fi; \ [2024-08-01T00:04:11.227Z] echo ""; echo "TEST TEARDOWN:"; \ [2024-08-01T00:04:11.227Z] echo "Nothing to be done for teardown."; \ [2024-08-01T00:04:11.227Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/TestTargetResult"; [2024-08-01T00:04:11.227Z] [2024-08-01T00:04:11.227Z] TEST SETUP: [2024-08-01T00:04:11.227Z] Nothing to be done for setup. [2024-08-01T00:04:11.227Z] [2024-08-01T00:04:11.227Z] TESTING: [2024-08-01T00:04:12.603Z] Directory "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1/work" not found: creating [2024-08-01T00:04:12.603Z] Directory "/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/../TKG/output_17224669911891/jdk_net_1/report" not found: creating [2024-08-01T00:04:41.854Z] XML output with verification to /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work [2024-08-01T01:21:44.543Z] -------------------------------------------------- [2024-08-01T01:21:44.543Z] TEST: java/net/httpclient/ISO_8859_1_Test.java [2024-08-01T01:21:44.543Z] TEST JDK: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image [2024-08-01T01:21:44.543Z] [2024-08-01T01:21:44.543Z] ACTION: build -- Passed. Build successful [2024-08-01T01:21:44.543Z] REASON: User specified action: run build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker [2024-08-01T01:21:44.543Z] TIME: 1.116 seconds [2024-08-01T01:21:44.543Z] messages: [2024-08-01T01:21:44.543Z] command: build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker [2024-08-01T01:21:44.543Z] reason: User specified action: run build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker [2024-08-01T01:21:44.543Z] started: Thu Aug 01 00:49:34 UTC 2024 [2024-08-01T01:21:44.543Z] Test directory: [2024-08-01T01:21:44.543Z] compile: ReferenceTracker [2024-08-01T01:21:44.543Z] finished: Thu Aug 01 00:49:36 UTC 2024 [2024-08-01T01:21:44.543Z] elapsed time (seconds): 1.116 [2024-08-01T01:21:44.543Z] [2024-08-01T01:21:44.543Z] ACTION: compile -- Passed. Compilation successful [2024-08-01T01:21:44.543Z] REASON: .class file out of date or does not exist [2024-08-01T01:21:44.543Z] TIME: 1.114 seconds [2024-08-01T01:21:44.543Z] messages: [2024-08-01T01:21:44.543Z] command: compile /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ReferenceTracker.java [2024-08-01T01:21:44.543Z] reason: .class file out of date or does not exist [2024-08-01T01:21:44.543Z] started: Thu Aug 01 00:49:34 UTC 2024 [2024-08-01T01:21:44.544Z] Additional options from @modules: --add-modules java.base,java.net.http,java.logging,jdk.httpserver --add-exports java.base/sun.net.www.http=ALL-UNNAMED --add-exports java.base/sun.net.www=ALL-UNNAMED --add-exports java.base/sun.net=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED [2024-08-01T01:21:44.544Z] Mode: agentvm [2024-08-01T01:21:44.544Z] Agent id: 3 [2024-08-01T01:21:44.544Z] finished: Thu Aug 01 00:49:36 UTC 2024 [2024-08-01T01:21:44.544Z] elapsed time (seconds): 1.114 [2024-08-01T01:21:44.544Z] configuration: [2024-08-01T01:21:44.544Z] Boot Layer (javac runtime environment) [2024-08-01T01:21:44.544Z] class path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/javatest.jar [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jtreg.jar [2024-08-01T01:21:44.544Z] patch: java.base /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/patches/java.base [2024-08-01T01:21:44.544Z] [2024-08-01T01:21:44.544Z] javac compilation environment [2024-08-01T01:21:44.544Z] add modules: java.base java.net.http java.logging jdk.httpserver [2024-08-01T01:21:44.544Z] add exports: java.base/sun.net ALL-UNNAMED [2024-08-01T01:21:44.544Z] java.base/sun.net.www ALL-UNNAMED [2024-08-01T01:21:44.544Z] java.base/sun.net.www.http ALL-UNNAMED [2024-08-01T01:21:44.544Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2024-08-01T01:21:44.544Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2024-08-01T01:21:44.544Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2024-08-01T01:21:44.544Z] source path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib [2024-08-01T01:21:44.544Z] class path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar [2024-08-01T01:21:44.544Z] [2024-08-01T01:21:44.544Z] rerun: [2024-08-01T01:21:44.544Z] cd /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/scratch/0 && \ [2024-08-01T01:21:44.544Z] DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1001/bus \ [2024-08-01T01:21:44.544Z] DISPLAY=:0 \ [2024-08-01T01:21:44.544Z] HOME=/home/jenkins \ [2024-08-01T01:21:44.544Z] LANG=en_US.UTF-8 \ [2024-08-01T01:21:44.544Z] PATH=/bin:/usr/bin:/usr/sbin \ [2024-08-01T01:21:44.544Z] XDG_RUNTIME_DIR=/run/user/1001 \ [2024-08-01T01:21:44.544Z] XDG_SESSION_CLASS=user \ [2024-08-01T01:21:44.544Z] XDG_SESSION_ID=679 \ [2024-08-01T01:21:44.544Z] XDG_SESSION_TYPE=tty \ [2024-08-01T01:21:44.544Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/javac \ [2024-08-01T01:21:44.544Z] -J-ea \ [2024-08-01T01:21:44.544Z] -J-esa \ [2024-08-01T01:21:44.544Z] -J-Xmx512m \ [2024-08-01T01:21:44.544Z] -J-XX:-UseCompressedOops \ [2024-08-01T01:21:44.544Z] -J-Djava.awt.headless=true \ [2024-08-01T01:21:44.544Z] -J-Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2024-08-01T01:21:44.544Z] -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2024-08-01T01:21:44.544Z] -J-Dtest.compiler.opts= \ [2024-08-01T01:21:44.544Z] -J-Dtest.java.opts= \ [2024-08-01T01:21:44.544Z] -J-Dtest.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.544Z] -J-Dcompile.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.544Z] -J-Dtest.timeout.factor=16.0 \ [2024-08-01T01:21:44.544Z] -J-Dtest.nativepath=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-01T01:21:44.545Z] -J-Dtest.root=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2024-08-01T01:21:44.545Z] -J-Dtest.name=java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.545Z] -J-Dtest.file=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.545Z] -J-Dtest.src=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient \ [2024-08-01T01:21:44.545Z] -J-Dtest.src.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.545Z] -J-Dtest.classes=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d \ [2024-08-01T01:21:44.545Z] -J-Dtest.class.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.545Z] -J-Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.545Z] -J-Dtest.modules='java.base/sun.net.www.http java.base/sun.net.www java.base/sun.net java.net.http/jdk.internal.net.http.common java.net.http/jdk.internal.net.http.frame java.net.http/jdk.internal.net.http.hpack java.logging jdk.httpserver' \ [2024-08-01T01:21:44.545Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2024-08-01T01:21:44.545Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2024-08-01T01:21:44.545Z] -d /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d \ [2024-08-01T01:21:44.545Z] -sourcepath /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.545Z] -classpath /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ReferenceTracker.java [2024-08-01T01:21:44.545Z] [2024-08-01T01:21:44.545Z] ACTION: build -- Passed. Build successful [2024-08-01T01:21:44.545Z] REASON: Named class compiled on demand [2024-08-01T01:21:44.545Z] TIME: 1.196 seconds [2024-08-01T01:21:44.545Z] messages: [2024-08-01T01:21:44.545Z] command: build ISO_8859_1_Test [2024-08-01T01:21:44.545Z] reason: Named class compiled on demand [2024-08-01T01:21:44.545Z] started: Thu Aug 01 00:49:36 UTC 2024 [2024-08-01T01:21:44.545Z] Test directory: [2024-08-01T01:21:44.545Z] compile: ISO_8859_1_Test [2024-08-01T01:21:44.545Z] finished: Thu Aug 01 00:49:37 UTC 2024 [2024-08-01T01:21:44.545Z] elapsed time (seconds): 1.196 [2024-08-01T01:21:44.545Z] [2024-08-01T01:21:44.545Z] ACTION: compile -- Passed. Compilation successful [2024-08-01T01:21:44.545Z] REASON: .class file out of date or does not exist [2024-08-01T01:21:44.545Z] TIME: 1.195 seconds [2024-08-01T01:21:44.545Z] messages: [2024-08-01T01:21:44.545Z] command: compile /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java [2024-08-01T01:21:44.545Z] reason: .class file out of date or does not exist [2024-08-01T01:21:44.545Z] started: Thu Aug 01 00:49:36 UTC 2024 [2024-08-01T01:21:44.546Z] Additional options from @modules: --add-modules java.base,java.net.http,java.logging,jdk.httpserver --add-exports java.base/sun.net.www.http=ALL-UNNAMED --add-exports java.base/sun.net.www=ALL-UNNAMED --add-exports java.base/sun.net=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED [2024-08-01T01:21:44.546Z] Mode: agentvm [2024-08-01T01:21:44.546Z] Agent id: 3 [2024-08-01T01:21:44.546Z] finished: Thu Aug 01 00:49:37 UTC 2024 [2024-08-01T01:21:44.546Z] elapsed time (seconds): 1.195 [2024-08-01T01:21:44.546Z] configuration: [2024-08-01T01:21:44.546Z] Boot Layer (javac runtime environment) [2024-08-01T01:21:44.546Z] class path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/javatest.jar [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jtreg.jar [2024-08-01T01:21:44.546Z] patch: java.base /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/patches/java.base [2024-08-01T01:21:44.546Z] [2024-08-01T01:21:44.546Z] javac compilation environment [2024-08-01T01:21:44.546Z] add modules: java.base java.net.http java.logging jdk.httpserver [2024-08-01T01:21:44.546Z] add exports: java.base/sun.net ALL-UNNAMED [2024-08-01T01:21:44.546Z] java.base/sun.net.www ALL-UNNAMED [2024-08-01T01:21:44.546Z] java.base/sun.net.www.http ALL-UNNAMED [2024-08-01T01:21:44.546Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2024-08-01T01:21:44.546Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2024-08-01T01:21:44.546Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2024-08-01T01:21:44.546Z] source path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib [2024-08-01T01:21:44.546Z] class path: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar [2024-08-01T01:21:44.546Z] [2024-08-01T01:21:44.546Z] rerun: [2024-08-01T01:21:44.546Z] cd /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/scratch/0 && \ [2024-08-01T01:21:44.546Z] DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1001/bus \ [2024-08-01T01:21:44.546Z] DISPLAY=:0 \ [2024-08-01T01:21:44.546Z] HOME=/home/jenkins \ [2024-08-01T01:21:44.546Z] LANG=en_US.UTF-8 \ [2024-08-01T01:21:44.546Z] PATH=/bin:/usr/bin:/usr/sbin \ [2024-08-01T01:21:44.546Z] XDG_RUNTIME_DIR=/run/user/1001 \ [2024-08-01T01:21:44.546Z] XDG_SESSION_CLASS=user \ [2024-08-01T01:21:44.546Z] XDG_SESSION_ID=679 \ [2024-08-01T01:21:44.546Z] XDG_SESSION_TYPE=tty \ [2024-08-01T01:21:44.546Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/javac \ [2024-08-01T01:21:44.546Z] -J-ea \ [2024-08-01T01:21:44.546Z] -J-esa \ [2024-08-01T01:21:44.546Z] -J-Xmx512m \ [2024-08-01T01:21:44.546Z] -J-XX:-UseCompressedOops \ [2024-08-01T01:21:44.546Z] -J-Djava.awt.headless=true \ [2024-08-01T01:21:44.546Z] -J-Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2024-08-01T01:21:44.546Z] -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2024-08-01T01:21:44.546Z] -J-Dtest.compiler.opts= \ [2024-08-01T01:21:44.546Z] -J-Dtest.java.opts= \ [2024-08-01T01:21:44.546Z] -J-Dtest.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.546Z] -J-Dcompile.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.546Z] -J-Dtest.timeout.factor=16.0 \ [2024-08-01T01:21:44.546Z] -J-Dtest.nativepath=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-01T01:21:44.546Z] -J-Dtest.root=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2024-08-01T01:21:44.546Z] -J-Dtest.name=java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.546Z] -J-Dtest.file=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.546Z] -J-Dtest.src=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient \ [2024-08-01T01:21:44.546Z] -J-Dtest.src.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.546Z] -J-Dtest.classes=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d \ [2024-08-01T01:21:44.546Z] -J-Dtest.class.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.546Z] -J-Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.546Z] -J-Dtest.modules='java.base/sun.net.www.http java.base/sun.net.www java.base/sun.net java.net.http/jdk.internal.net.http.common java.net.http/jdk.internal.net.http.frame java.net.http/jdk.internal.net.http.hpack java.logging jdk.httpserver' \ [2024-08-01T01:21:44.546Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2024-08-01T01:21:44.546Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2024-08-01T01:21:44.546Z] -d /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d \ [2024-08-01T01:21:44.546Z] -sourcepath /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.546Z] -classpath /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java [2024-08-01T01:21:44.546Z] direct: [2024-08-01T01:21:44.546Z] Note: /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java uses unchecked or unsafe operations. [2024-08-01T01:21:44.546Z] Note: Recompile with -Xlint:unchecked for details. [2024-08-01T01:21:44.546Z] [2024-08-01T01:21:44.546Z] ACTION: testng -- Error. Program `/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/java' timed out (timeout set to 1920000ms, elapsed time including timeout handling was 1921502ms). [2024-08-01T01:21:44.546Z] REASON: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.HttpClient.log=requests,responses,errors ISO_8859_1_Test [2024-08-01T01:21:44.546Z] TIME: 1921.556 seconds [2024-08-01T01:21:44.546Z] messages: [2024-08-01T01:21:44.546Z] command: testng -Djdk.internal.httpclient.debug=true -Djdk.httpclient.HttpClient.log=requests,responses,errors ISO_8859_1_Test [2024-08-01T01:21:44.546Z] reason: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.HttpClient.log=requests,responses,errors ISO_8859_1_Test [2024-08-01T01:21:44.546Z] started: Thu Aug 01 00:49:37 UTC 2024 [2024-08-01T01:21:44.546Z] Mode: othervm [/othervm specified] [2024-08-01T01:21:44.546Z] Additional options from @modules: --add-modules java.base,java.net.http,java.logging,jdk.httpserver --add-exports java.base/sun.net.www.http=ALL-UNNAMED --add-exports java.base/sun.net.www=ALL-UNNAMED --add-exports java.base/sun.net=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED [2024-08-01T01:21:44.546Z] Timeout information: [2024-08-01T01:21:44.546Z] Running jstack on process 1686121 [2024-08-01T01:21:44.546Z] 2024-08-01 01:21:38 [2024-08-01T01:21:44.546Z] Full thread dump OpenJDK 64-Bit Server VM (21.0.5-beta+1-ea mixed mode, sharing): [2024-08-01T01:21:44.546Z] [2024-08-01T01:21:44.546Z] Threads class SMR info: [2024-08-01T01:21:44.546Z] _java_thread_list=0x0000003f28002030, length=24, elements={ [2024-08-01T01:21:44.546Z] 0x0000003fd802ed10, 0x0000003fd813df80, 0x0000003fd813f4e0, 0x0000003fd8140c70, [2024-08-01T01:21:44.547Z] 0x0000003fd81422a0, 0x0000003fd8143830, 0x0000003fd8145360, 0x0000003fd8146a10, [2024-08-01T01:21:44.547Z] 0x0000003fd819ff40, 0x0000003fd81e36a0, 0x0000003fd8220cd0, 0x0000003f141cfa90, [2024-08-01T01:21:44.547Z] 0x0000003f142347f0, 0x0000003f141bd640, 0x0000003f141a6050, 0x0000003f141a7860, [2024-08-01T01:21:44.547Z] 0x0000003f141a8950, 0x0000003f141a9d10, 0x0000003f142a05e0, 0x0000003f142bf3c0, [2024-08-01T01:21:44.547Z] 0x0000003f142c5590, 0x0000003ee0010160, 0x0000003f142ca740, 0x0000003f28000ff0 [2024-08-01T01:21:44.547Z] } [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "main" #1 [1686125] prio=5 os_prio=0 cpu=707.94ms elapsed=1921.30s tid=0x0000003fd802ed10 nid=1686125 in Object.wait() [0x0000003fddffb000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: WAITING (on object monitor) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait0(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - waiting on <0x0000003fa0868410> (a java.lang.Thread) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait(java.base@21.0.5-beta/Object.java:366) [2024-08-01T01:21:44.547Z] at java.lang.Thread.join(java.base@21.0.5-beta/Thread.java:2079) [2024-08-01T01:21:44.547Z] - locked <0x0000003fa0868410> (a java.lang.Thread) [2024-08-01T01:21:44.547Z] at java.lang.Thread.join(java.base@21.0.5-beta/Thread.java:2155) [2024-08-01T01:21:44.547Z] at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:85) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Reference Handler" #9 [1686138] daemon prio=10 os_prio=0 cpu=9.10ms elapsed=1920.91s tid=0x0000003fd813df80 nid=1686138 waiting on condition [0x0000003f917bc000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] at java.lang.ref.Reference.waitForReferencePendingList(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] at java.lang.ref.Reference.processPendingReferences(java.base@21.0.5-beta/Reference.java:246) [2024-08-01T01:21:44.547Z] at java.lang.ref.Reference$ReferenceHandler.run(java.base@21.0.5-beta/Reference.java:208) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Finalizer" #10 [1686139] daemon prio=8 os_prio=0 cpu=1.01ms elapsed=1920.91s tid=0x0000003fd813f4e0 nid=1686139 in Object.wait() [0x0000003f915bc000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: WAITING (on object monitor) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait0(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - waiting on <0x0000003fa086ca98> (a java.lang.ref.NativeReferenceQueue$Lock) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait(java.base@21.0.5-beta/Object.java:366) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait(java.base@21.0.5-beta/Object.java:339) [2024-08-01T01:21:44.547Z] at java.lang.ref.NativeReferenceQueue.await(java.base@21.0.5-beta/NativeReferenceQueue.java:48) [2024-08-01T01:21:44.547Z] at java.lang.ref.ReferenceQueue.remove0(java.base@21.0.5-beta/ReferenceQueue.java:158) [2024-08-01T01:21:44.547Z] at java.lang.ref.NativeReferenceQueue.remove(java.base@21.0.5-beta/NativeReferenceQueue.java:89) [2024-08-01T01:21:44.547Z] - locked <0x0000003fa086ca98> (a java.lang.ref.NativeReferenceQueue$Lock) [2024-08-01T01:21:44.547Z] at java.lang.ref.Finalizer$FinalizerThread.run(java.base@21.0.5-beta/Finalizer.java:173) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Signal Dispatcher" #11 [1686140] daemon prio=9 os_prio=0 cpu=1.07ms elapsed=1920.91s tid=0x0000003fd8140c70 nid=1686140 waiting on condition [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Service Thread" #12 [1686141] daemon prio=9 os_prio=0 cpu=1.45ms elapsed=1920.89s tid=0x0000003fd81422a0 nid=1686141 runnable [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Monitor Deflation Thread" #13 [1686143] daemon prio=9 os_prio=0 cpu=499.96ms elapsed=1920.87s tid=0x0000003fd8143830 nid=1686143 runnable [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "C2 CompilerThread0" #14 [1686144] daemon prio=9 os_prio=0 cpu=4715.83ms elapsed=1920.86s tid=0x0000003fd8145360 nid=1686144 waiting on condition [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] No compile task [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "C1 CompilerThread0" #16 [1686145] daemon prio=9 os_prio=0 cpu=3473.40ms elapsed=1920.85s tid=0x0000003fd8146a10 nid=1686145 waiting on condition [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] No compile task [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Common-Cleaner" #17 [1686158] daemon prio=8 os_prio=0 cpu=17.55ms elapsed=1920.39s tid=0x0000003fd819ff40 nid=1686158 waiting on condition [0x0000003f909bb000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: TIMED_WAITING (parking) [2024-08-01T01:21:44.547Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - parking to wait for <0x0000003fa0864018> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) [2024-08-01T01:21:44.547Z] at java.util.concurrent.locks.LockSupport.parkNanos(java.base@21.0.5-beta/LockSupport.java:269) [2024-08-01T01:21:44.547Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:1852) [2024-08-01T01:21:44.547Z] at java.lang.ref.ReferenceQueue.await(java.base@21.0.5-beta/ReferenceQueue.java:71) [2024-08-01T01:21:44.547Z] at java.lang.ref.ReferenceQueue.remove0(java.base@21.0.5-beta/ReferenceQueue.java:143) [2024-08-01T01:21:44.547Z] at java.lang.ref.ReferenceQueue.remove(java.base@21.0.5-beta/ReferenceQueue.java:218) [2024-08-01T01:21:44.547Z] at jdk.internal.ref.CleanerImpl.run(java.base@21.0.5-beta/CleanerImpl.java:140) [2024-08-01T01:21:44.547Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.547Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.547Z] at jdk.internal.misc.InnocuousThread.run(java.base@21.0.5-beta/InnocuousThread.java:186) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "Notification Thread" #18 [1686165] daemon prio=9 os_prio=0 cpu=0.45ms elapsed=1919.78s tid=0x0000003fd81e36a0 nid=1686165 runnable [0x0000000000000000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "MainThread" #19 [1686175] prio=5 os_prio=0 cpu=4760.25ms elapsed=1919.49s tid=0x0000003fd8220cd0 nid=1686175 waiting on condition [0x0000003f905ba000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: WAITING (parking) [2024-08-01T01:21:44.547Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - parking to wait for <0x0000003fafad49a0> (a java.util.concurrent.CompletableFuture$Signaller) [2024-08-01T01:21:44.547Z] at java.util.concurrent.locks.LockSupport.park(java.base@21.0.5-beta/LockSupport.java:221) [2024-08-01T01:21:44.547Z] at java.util.concurrent.CompletableFuture$Signaller.block(java.base@21.0.5-beta/CompletableFuture.java:1864) [2024-08-01T01:21:44.547Z] at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@21.0.5-beta/ForkJoinPool.java:3780) [2024-08-01T01:21:44.547Z] at java.util.concurrent.ForkJoinPool.managedBlock(java.base@21.0.5-beta/ForkJoinPool.java:3725) [2024-08-01T01:21:44.547Z] at java.util.concurrent.CompletableFuture.waitingGet(java.base@21.0.5-beta/CompletableFuture.java:1898) [2024-08-01T01:21:44.547Z] at java.util.concurrent.CompletableFuture.join(java.base@21.0.5-beta/CompletableFuture.java:2117) [2024-08-01T01:21:44.547Z] at ISO_8859_1_Test.test(ISO_8859_1_Test.java:294) [2024-08-01T01:21:44.547Z] at java.lang.invoke.LambdaForm$DMH/0x0000003f44105c00.invokeVirtual(java.base@21.0.5-beta/LambdaForm$DMH) [2024-08-01T01:21:44.547Z] at java.lang.invoke.LambdaForm$MH/0x0000003f4410a000.invoke(java.base@21.0.5-beta/LambdaForm$MH) [2024-08-01T01:21:44.547Z] at java.lang.invoke.LambdaForm$MH/0x0000003f4410a400.invokeExact_MT(java.base@21.0.5-beta/LambdaForm$MH) [2024-08-01T01:21:44.547Z] at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.5-beta/DirectMethodHandleAccessor.java:155) [2024-08-01T01:21:44.547Z] at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.5-beta/DirectMethodHandleAccessor.java:103) [2024-08-01T01:21:44.547Z] at java.lang.reflect.Method.invoke(java.base@21.0.5-beta/Method.java:580) [2024-08-01T01:21:44.547Z] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) [2024-08-01T01:21:44.547Z] at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) [2024-08-01T01:21:44.547Z] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) [2024-08-01T01:21:44.547Z] at org.testng.TestRunner$$Lambda/0x0000003f440dd000.accept(Unknown Source) [2024-08-01T01:21:44.547Z] at java.util.ArrayList.forEach(java.base@21.0.5-beta/ArrayList.java:1596) [2024-08-01T01:21:44.547Z] at org.testng.TestRunner.privateRun(TestRunner.java:764) [2024-08-01T01:21:44.547Z] at org.testng.TestRunner.run(TestRunner.java:585) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunner.run(SuiteRunner.java:286) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) [2024-08-01T01:21:44.547Z] at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) [2024-08-01T01:21:44.547Z] at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) [2024-08-01T01:21:44.547Z] at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) [2024-08-01T01:21:44.547Z] at org.testng.TestNG.runSuites(TestNG.java:1069) [2024-08-01T01:21:44.547Z] at org.testng.TestNG.run(TestNG.java:1037) [2024-08-01T01:21:44.547Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) [2024-08-01T01:21:44.547Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2024-08-01T01:21:44.547Z] at java.lang.invoke.LambdaForm$DMH/0x0000003f44002000.invokeStatic(java.base@21.0.5-beta/LambdaForm$DMH) [2024-08-01T01:21:44.547Z] at java.lang.invoke.LambdaForm$MH/0x0000003f44003400.invoke(java.base@21.0.5-beta/LambdaForm$MH) [2024-08-01T01:21:44.547Z] at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@21.0.5-beta/Invokers$Holder) [2024-08-01T01:21:44.547Z] at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl(java.base@21.0.5-beta/DirectMethodHandleAccessor.java:154) [2024-08-01T01:21:44.547Z] at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(java.base@21.0.5-beta/DirectMethodHandleAccessor.java:103) [2024-08-01T01:21:44.547Z] at java.lang.reflect.Method.invoke(java.base@21.0.5-beta/Method.java:580) [2024-08-01T01:21:44.547Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2024-08-01T01:21:44.547Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.547Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "idle-timeout-task" #24 [1686376] daemon prio=5 os_prio=0 cpu=57.80ms elapsed=1910.08s tid=0x0000003f141cfa90 nid=1686376 in Object.wait() [0x0000003f3e9fb000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: TIMED_WAITING (on object monitor) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait0(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - waiting on <no object reference available> [2024-08-01T01:21:44.547Z] at java.lang.Object.wait(java.base@21.0.5-beta/Object.java:366) [2024-08-01T01:21:44.547Z] at java.util.TimerThread.mainLoop(java.base@21.0.5-beta/Timer.java:563) [2024-08-01T01:21:44.547Z] - locked <0x0000003faeb000b8> (a java.util.TaskQueue) [2024-08-01T01:21:44.547Z] at java.util.TimerThread.run(java.base@21.0.5-beta/Timer.java:516) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "idle-timeout-task" #25 [1686377] daemon prio=5 os_prio=0 cpu=39.70ms elapsed=1909.73s tid=0x0000003f142347f0 nid=1686377 in Object.wait() [0x0000003f3e7fb000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: TIMED_WAITING (on object monitor) [2024-08-01T01:21:44.547Z] at java.lang.Object.wait0(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] - waiting on <no object reference available> [2024-08-01T01:21:44.547Z] at java.lang.Object.wait(java.base@21.0.5-beta/Object.java:366) [2024-08-01T01:21:44.547Z] at java.util.TimerThread.mainLoop(java.base@21.0.5-beta/Timer.java:563) [2024-08-01T01:21:44.547Z] - locked <0x0000003faeb28f98> (a java.util.TaskQueue) [2024-08-01T01:21:44.547Z] at java.util.TimerThread.run(java.base@21.0.5-beta/Timer.java:516) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "HTTP-Dispatcher" #26 [1686388] prio=5 os_prio=0 cpu=679.01ms elapsed=1908.77s tid=0x0000003f141bd640 nid=1686388 runnable [0x0000003f903bb000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] at sun.nio.ch.EPoll.wait(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@21.0.5-beta/EPollSelectorImpl.java:121) [2024-08-01T01:21:44.547Z] at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@21.0.5-beta/SelectorImpl.java:130) [2024-08-01T01:21:44.547Z] - locked <0x0000003faeb14a70> (a sun.nio.ch.Util$2) [2024-08-01T01:21:44.547Z] - locked <0x0000003faeb149e8> (a sun.nio.ch.EPollSelectorImpl) [2024-08-01T01:21:44.547Z] at sun.nio.ch.SelectorImpl.select(java.base@21.0.5-beta/SelectorImpl.java:142) [2024-08-01T01:21:44.547Z] at sun.net.httpserver.ServerImpl$Dispatcher.run(jdk.httpserver@21.0.5-beta/ServerImpl.java:473) [2024-08-01T01:21:44.547Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.547Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.547Z] [2024-08-01T01:21:44.547Z] "HTTP-Dispatcher" #27 [1686389] prio=5 os_prio=0 cpu=315.36ms elapsed=1908.75s tid=0x0000003f141a6050 nid=1686389 runnable [0x0000003f3e5fa000] [2024-08-01T01:21:44.547Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.547Z] at sun.nio.ch.EPoll.wait(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.547Z] at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@21.0.5-beta/EPollSelectorImpl.java:121) [2024-08-01T01:21:44.547Z] at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@21.0.5-beta/SelectorImpl.java:130) [2024-08-01T01:21:44.548Z] - locked <0x0000003faeb002f8> (a sun.nio.ch.Util$2) [2024-08-01T01:21:44.548Z] - locked <0x0000003faeb00270> (a sun.nio.ch.EPollSelectorImpl) [2024-08-01T01:21:44.548Z] at sun.nio.ch.SelectorImpl.select(java.base@21.0.5-beta/SelectorImpl.java:142) [2024-08-01T01:21:44.548Z] at sun.net.httpserver.ServerImpl$Dispatcher.run(jdk.httpserver@21.0.5-beta/ServerImpl.java:473) [2024-08-01T01:21:44.548Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.548Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "Test-server-pool" #28 [1686390] prio=5 os_prio=0 cpu=12.00ms elapsed=1908.73s tid=0x0000003f141a7860 nid=1686390 runnable [0x0000003f3e3fa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.548Z] at sun.nio.ch.Net.accept(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] at sun.nio.ch.NioSocketImpl.accept(java.base@21.0.5-beta/NioSocketImpl.java:748) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:698) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.platformImplAccept(java.base@21.0.5-beta/ServerSocket.java:663) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:639) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:585) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.accept(java.base@21.0.5-beta/ServerSocket.java:543) [2024-08-01T01:21:44.548Z] at jdk.httpclient.test.lib.http2.Http2TestServer.lambda$start$2(Http2TestServer.java:350) [2024-08-01T01:21:44.548Z] at jdk.httpclient.test.lib.http2.Http2TestServer$$Lambda/0x0000003f440cece0.run(Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.Executors$RunnableAdapter.call(java.base@21.0.5-beta/Executors.java:572) [2024-08-01T01:21:44.548Z] at java.util.concurrent.FutureTask.run(java.base@21.0.5-beta/FutureTask.java:317) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.5-beta/ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.5-beta/ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.548Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.548Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "Test-server-pool" #29 [1686391] prio=5 os_prio=0 cpu=4.11ms elapsed=1908.72s tid=0x0000003f141a8950 nid=1686391 runnable [0x0000003f3e1fa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.548Z] at sun.nio.ch.Net.accept(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] at sun.nio.ch.NioSocketImpl.accept(java.base@21.0.5-beta/NioSocketImpl.java:748) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:698) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.platformImplAccept(java.base@21.0.5-beta/ServerSocket.java:663) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:612) [2024-08-01T01:21:44.548Z] at sun.security.ssl.SSLServerSocketImpl.accept(java.base@21.0.5-beta/SSLServerSocketImpl.java:271) [2024-08-01T01:21:44.548Z] at jdk.httpclient.test.lib.http2.Http2TestServer.lambda$start$2(Http2TestServer.java:350) [2024-08-01T01:21:44.548Z] at jdk.httpclient.test.lib.http2.Http2TestServer$$Lambda/0x0000003f440cece0.run(Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.Executors$RunnableAdapter.call(java.base@21.0.5-beta/Executors.java:572) [2024-08-01T01:21:44.548Z] at java.util.concurrent.FutureTask.run(java.base@21.0.5-beta/FutureTask.java:317) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.5-beta/ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.5-beta/ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.548Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.548Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "Thread-1" #23 [1686392] prio=5 os_prio=0 cpu=31.37ms elapsed=1908.72s tid=0x0000003f141a9d10 nid=1686392 runnable [0x0000003f3dffa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.548Z] at sun.nio.ch.Net.accept(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] at sun.nio.ch.NioSocketImpl.accept(java.base@21.0.5-beta/NioSocketImpl.java:748) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:698) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.platformImplAccept(java.base@21.0.5-beta/ServerSocket.java:663) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:639) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.implAccept(java.base@21.0.5-beta/ServerSocket.java:585) [2024-08-01T01:21:44.548Z] at java.net.ServerSocket.accept(java.base@21.0.5-beta/ServerSocket.java:543) [2024-08-01T01:21:44.548Z] at ISO_8859_1_Test$DummyServer.run(ISO_8859_1_Test.java:349) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "HttpClient-1-SelectorManager" #30 [1686399] daemon prio=5 os_prio=0 cpu=240.56ms elapsed=1907.19s tid=0x0000003f142a05e0 nid=1686399 runnable [0x0000003f3ddfb000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.548Z] at sun.nio.ch.EPoll.wait(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@21.0.5-beta/EPollSelectorImpl.java:121) [2024-08-01T01:21:44.548Z] at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@21.0.5-beta/SelectorImpl.java:130) [2024-08-01T01:21:44.548Z] - locked <0x0000003faeb15058> (a sun.nio.ch.Util$2) [2024-08-01T01:21:44.548Z] - locked <0x0000003faeb14fd0> (a sun.nio.ch.EPollSelectorImpl) [2024-08-01T01:21:44.548Z] at sun.nio.ch.SelectorImpl.select(java.base@21.0.5-beta/SelectorImpl.java:142) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.HttpClientImpl$SelectorManager.run(java.net.http@21.0.5-beta/HttpClientImpl.java:1366) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "pool-1-thread-1" #31 [1686400] prio=5 os_prio=0 cpu=415.06ms elapsed=1907.00s tid=0x0000003f142bf3c0 nid=1686400 waiting on condition [0x0000003f3dbfa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: WAITING (parking) [2024-08-01T01:21:44.548Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] - parking to wait for <0x0000003fafacec28> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.LockSupport.park(java.base@21.0.5-beta/LockSupport.java:221) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:754) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:990) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@21.0.5-beta/ReentrantLock.java:153) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.ReentrantLock.lock(java.base@21.0.5-beta/ReentrantLock.java:322) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.HttpClientImpl$SelectorManager.register(java.net.http@21.0.5-beta/HttpClientImpl.java:1159) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.HttpClientImpl.registerEvent(java.net.http@21.0.5-beta/HttpClientImpl.java:882) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalSubscribe(java.net.http@21.0.5-beta/SocketTube.java:694) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.SocketTube$InternalReadPublisher.subscribe(java.net.http@21.0.5-beta/SocketTube.java:585) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.SocketTube.subscribe(java.net.http@21.0.5-beta/SocketTube.java:113) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.SocketTube.connectFlows(java.net.http@21.0.5-beta/SocketTube.java:1297) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Http1Exchange.connectFlows(java.net.http@21.0.5-beta/Http1Exchange.java:263) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Http1Exchange.lambda$sendHeadersAsync$4(java.net.http@21.0.5-beta/Http1Exchange.java:348) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Http1Exchange$$Lambda/0x0000003f44157400.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture$UniCompose.tryFire(java.base@21.0.5-beta/CompletableFuture.java:1150) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture.postComplete(java.base@21.0.5-beta/CompletableFuture.java:510) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture$AsyncSupply.run(java.base@21.0.5-beta/CompletableFuture.java:1773) [2024-08-01T01:21:44.548Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.548Z] at ISO_8859_1_Test$TestExecutor$$Lambda/0x0000003f44106890.run(Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.5-beta/ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.5-beta/ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.548Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.548Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "pool-1-thread-4" #34 [1686403] prio=5 os_prio=0 cpu=305.07ms elapsed=1906.92s tid=0x0000003f142c5590 nid=1686403 waiting on condition [0x0000003f3d5fa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: WAITING (parking) [2024-08-01T01:21:44.548Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] - parking to wait for <0x0000003fafacec28> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.LockSupport.park(java.base@21.0.5-beta/LockSupport.java:221) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:754) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:990) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@21.0.5-beta/ReentrantLock.java:153) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.ReentrantLock.lock(java.base@21.0.5-beta/ReentrantLock.java:322) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.HttpClientImpl$SelectorManager.register(java.net.http@21.0.5-beta/HttpClientImpl.java:1159) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.HttpClientImpl.registerEvent(java.net.http@21.0.5-beta/HttpClientImpl.java:882) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.PlainHttpConnection.connectAsync(java.net.http@21.0.5-beta/PlainHttpConnection.java:223) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Http1Exchange.sendHeadersAsync(java.net.http@21.0.5-beta/Http1Exchange.java:312) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$8(java.net.http@21.0.5-beta/Exchange.java:567) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange$$Lambda/0x0000003f4412c438.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.checkFor407(java.net.http@21.0.5-beta/Exchange.java:447) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(java.net.http@21.0.5-beta/Exchange.java:571) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange$$Lambda/0x0000003f4413f2c8.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture.uniHandle(java.base@21.0.5-beta/CompletableFuture.java:934) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture.uniHandleStage(java.base@21.0.5-beta/CompletableFuture.java:950) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture.handle(java.base@21.0.5-beta/CompletableFuture.java:2372) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.responseAsyncImpl0(java.net.http@21.0.5-beta/Exchange.java:571) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.responseAsyncImpl(java.net.http@21.0.5-beta/Exchange.java:423) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.Exchange.responseAsync(java.net.http@21.0.5-beta/Exchange.java:415) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.MultiExchange.responseAsyncImpl(java.net.http@21.0.5-beta/MultiExchange.java:413) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(java.net.http@21.0.5-beta/MultiExchange.java:346) [2024-08-01T01:21:44.548Z] at jdk.internal.net.http.MultiExchange$$Lambda/0x0000003f44127bb8.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture$UniCompose.tryFire(java.base@21.0.5-beta/CompletableFuture.java:1150) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture.postComplete(java.base@21.0.5-beta/CompletableFuture.java:510) [2024-08-01T01:21:44.548Z] at java.util.concurrent.CompletableFuture$AsyncSupply.run(java.base@21.0.5-beta/CompletableFuture.java:1773) [2024-08-01T01:21:44.548Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.548Z] at ISO_8859_1_Test$TestExecutor$$Lambda/0x0000003f44106890.run(Unknown Source) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.5-beta/ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.548Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.5-beta/ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.548Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.548Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.548Z] [2024-08-01T01:21:44.548Z] "pool-1-thread-9" #39 [1686431] prio=5 os_prio=0 cpu=186.95ms elapsed=1906.18s tid=0x0000003ee0010160 nid=1686431 waiting on condition [0x0000003f3c9fa000] [2024-08-01T01:21:44.548Z] java.lang.Thread.State: WAITING (parking) [2024-08-01T01:21:44.548Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.548Z] - parking to wait for <0x0000003fafacec28> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) [2024-08-01T01:21:44.548Z] at java.util.concurrent.locks.LockSupport.park(java.base@21.0.5-beta/LockSupport.java:221) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:754) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:990) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@21.0.5-beta/ReentrantLock.java:153) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.ReentrantLock.lock(java.base@21.0.5-beta/ReentrantLock.java:322) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.HttpClientImpl$SelectorManager.register(java.net.http@21.0.5-beta/HttpClientImpl.java:1159) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.HttpClientImpl.registerEvent(java.net.http@21.0.5-beta/HttpClientImpl.java:882) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.PlainHttpConnection.connectAsync(java.net.http@21.0.5-beta/PlainHttpConnection.java:223) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Http1Exchange.sendHeadersAsync(java.net.http@21.0.5-beta/Http1Exchange.java:312) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$8(java.net.http@21.0.5-beta/Exchange.java:567) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange$$Lambda/0x0000003f4412c438.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.checkFor407(java.net.http@21.0.5-beta/Exchange.java:447) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(java.net.http@21.0.5-beta/Exchange.java:571) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange$$Lambda/0x0000003f4413f2c8.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture.uniHandle(java.base@21.0.5-beta/CompletableFuture.java:934) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture.uniHandleStage(java.base@21.0.5-beta/CompletableFuture.java:950) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture.handle(java.base@21.0.5-beta/CompletableFuture.java:2372) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.responseAsyncImpl0(java.net.http@21.0.5-beta/Exchange.java:571) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.responseAsyncImpl(java.net.http@21.0.5-beta/Exchange.java:423) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.Exchange.responseAsync(java.net.http@21.0.5-beta/Exchange.java:415) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.MultiExchange.responseAsyncImpl(java.net.http@21.0.5-beta/MultiExchange.java:413) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(java.net.http@21.0.5-beta/MultiExchange.java:346) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.MultiExchange$$Lambda/0x0000003f44127bb8.apply(java.net.http@21.0.5-beta/Unknown Source) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture$UniCompose.tryFire(java.base@21.0.5-beta/CompletableFuture.java:1150) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture.postComplete(java.base@21.0.5-beta/CompletableFuture.java:510) [2024-08-01T01:21:44.549Z] at java.util.concurrent.CompletableFuture$AsyncSupply.run(java.base@21.0.5-beta/CompletableFuture.java:1773) [2024-08-01T01:21:44.549Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.549Z] at ISO_8859_1_Test$TestExecutor$$Lambda/0x0000003f44106890.run(Unknown Source) [2024-08-01T01:21:44.549Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.5-beta/ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.549Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.5-beta/ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.549Z] at java.lang.Thread.runWith(java.base@21.0.5-beta/Thread.java:1596) [2024-08-01T01:21:44.549Z] at java.lang.Thread.run(java.base@21.0.5-beta/Thread.java:1583) [2024-08-01T01:21:44.549Z] [2024-08-01T01:21:44.549Z] "HttpClient-2-SelectorManager" #43 [1686439] daemon prio=5 os_prio=0 cpu=9.62ms elapsed=1905.14s tid=0x0000003f142ca740 nid=1686439 waiting on condition [0x0000003edfffd000] [2024-08-01T01:21:44.549Z] java.lang.Thread.State: WAITING (parking) [2024-08-01T01:21:44.549Z] at jdk.internal.misc.Unsafe.park(java.base@21.0.5-beta/Native Method) [2024-08-01T01:21:44.549Z] - parking to wait for <0x0000003fa0917258> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.LockSupport.park(java.base@21.0.5-beta/LockSupport.java:221) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:754) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.5-beta/AbstractQueuedSynchronizer.java:990) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@21.0.5-beta/ReentrantLock.java:153) [2024-08-01T01:21:44.549Z] at java.util.concurrent.locks.ReentrantLock.lock(java.base@21.0.5-beta/ReentrantLock.java:322) [2024-08-01T01:21:44.549Z] at jdk.internal.misc.InternalLock.lock(java.base@21.0.5-beta/InternalLock.java:74) [2024-08-01T01:21:44.549Z] at java.io.PrintStream.writeln(java.base@21.0.5-beta/PrintStream.java:824) [2024-08-01T01:21:44.549Z] at java.io.PrintStream.println(java.base@21.0.5-beta/PrintStream.java:1168) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.common.DebugLogger.print(java.net.http@21.0.5-beta/DebugLogger.java:290) [2024-08-01T01:21:44.549Z] at jdk.internal.net.http.common.DebugLogger.log(java.net.http@21.0.5-beta/DebugLogger.java:238) [2024-08-01T01:21:44.549Z] at java.lang.System$Logger.log(java.base@21.0.5-beta/System.java:1506) [2024-08-01T01:21:44.554Z] at jdk.internal.net.http.common.Logger.log(java.net.http@21.0.5-beta/Logger.java:154) [2024-08-01T01:21:44.554Z] at jdk.internal.net.http.HttpClientImpl$SelectorAttachment.register(java.net.http@21.0.5-beta/HttpClientImpl.java:1527) [2024-08-01T01:21:44.554Z] at jdk.internal.net.http.HttpClientImpl$SelectorManager.run(java.net.http@21.0.5-beta/HttpClientImpl.java:1288) [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "Attach Listener" #44 [1701422] daemon prio=9 os_prio=0 cpu=1.09ms elapsed=0.11s tid=0x0000003f28000ff0 nid=1701422 waiting on condition [0x0000000000000000] [2024-08-01T01:21:44.554Z] java.lang.Thread.State: RUNNABLE [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "GC Thread#3" os_prio=0 cpu=46.28ms elapsed=1913.89s tid=0x0000003f380080f0 nid=1686304 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "GC Thread#2" os_prio=0 cpu=41.30ms elapsed=1913.90s tid=0x0000003f380075e0 nid=1686303 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "GC Thread#1" os_prio=0 cpu=69.66ms elapsed=1913.94s tid=0x0000003f38006b80 nid=1686302 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "VM Thread" os_prio=0 cpu=170.13ms elapsed=1921.01s tid=0x0000003fd81347d0 nid=1686135 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "VM Periodic Task Thread" os_prio=0 cpu=2465.85ms elapsed=1921.10s tid=0x0000003fd8123370 nid=1686133 waiting on condition [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "G1 Service" os_prio=0 cpu=155.05ms elapsed=1921.25s tid=0x0000003fd81134d0 nid=1686130 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "G1 Refine#0" os_prio=0 cpu=4096.56ms elapsed=1921.26s tid=0x0000003fd8112520 nid=1686129 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "G1 Conc#0" os_prio=0 cpu=0.13ms elapsed=1921.28s tid=0x0000003fd8060020 nid=1686128 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "G1 Main Marker" os_prio=0 cpu=0.23ms elapsed=1921.29s tid=0x0000003fd805f080 nid=1686127 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] "GC Thread#0" os_prio=0 cpu=40.05ms elapsed=1921.30s tid=0x0000003fd8059820 nid=1686126 runnable [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] JNI global refs: 16, weak refs: 0 [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] --- Timeout information end. [2024-08-01T01:21:44.554Z] finished: Thu Aug 01 01:21:38 UTC 2024 [2024-08-01T01:21:44.554Z] elapsed time (seconds): 1921.556 [2024-08-01T01:21:44.554Z] configuration: [2024-08-01T01:21:44.554Z] Boot Layer [2024-08-01T01:21:44.554Z] add modules: java.base java.net.http java.logging jdk.httpserver [2024-08-01T01:21:44.554Z] add exports: java.base/sun.net ALL-UNNAMED [2024-08-01T01:21:44.554Z] java.base/sun.net.www ALL-UNNAMED [2024-08-01T01:21:44.554Z] java.base/sun.net.www.http ALL-UNNAMED [2024-08-01T01:21:44.554Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2024-08-01T01:21:44.554Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2024-08-01T01:21:44.554Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] STDOUT: [2024-08-01T01:21:44.554Z] Http1TestServer[localhost/127.0.0.1:44623]::addHandler ISO_8859_1_Test$ISO88591Handler@49a9e908, /http1/server/ [2024-08-01T01:21:44.554Z] Http1TestServer[localhost/127.0.0.1:43983]::addHandler ISO_8859_1_Test$ISO88591Handler@49a9e908, /https1/server/ [2024-08-01T01:21:44.554Z] Http2TestServerImpl[localhost/127.0.0.1:47451]::addHandler ISO_8859_1_Test$ISO88591Handler@49a9e908, /http2/server/ [2024-08-01T01:21:44.554Z] Http2TestServerImpl[localhost/127.0.0.1:45507]::addHandler ISO_8859_1_Test$ISO88591Handler@49a9e908, /https2/server/ [2024-08-01T01:21:44.554Z] Http1TestServer: start [2024-08-01T01:21:44.554Z] Http1TestServer: start [2024-08-01T01:21:44.554Z] Http2TestServerImpl: start [2024-08-01T01:21:44.554Z] Http2TestServerImpl: start [2024-08-01T01:21:44.554Z] config ISO_8859_1_Test.setup(): success [2024-08-01T01:21:44.554Z] config ISO_8859_1_Test.beforeMethod(org.testng.TestRunner@375b214): success [2024-08-01T01:21:44.554Z] Request to http://127.0.0.1:37231/http1/dummy/x [2024-08-01T01:21:44.554Z] Accepted: Socket[addr=/127.0.0.1,port=54118,localport=37231] [2024-08-01T01:21:44.554Z] Got line: GET /http1/dummy/x/0 HTTP/1.1 [2024-08-01T01:21:44.554Z] Got line: Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Got line: Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Got line: HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Got line: Upgrade: h2c [2024-08-01T01:21:44.554Z] Got line: User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] GET /http1/dummy/x/0 HTTP/1.1 [2024-08-01T01:21:44.554Z] Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Upgrade: h2c [2024-08-01T01:21:44.554Z] User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Sending back HTTP/1.1 200 OK [2024-08-01T01:21:44.554Z] Content-length: 0 [2024-08-01T01:21:44.554Z] Header8859: UÿU [2024-08-01T01:21:44.554Z] Connection: close [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Accepted: Socket[addr=/127.0.0.1,port=54120,localport=37231] [2024-08-01T01:21:44.554Z] Got line: GET /http1/dummy/x/1 HTTP/1.1 [2024-08-01T01:21:44.554Z] Got line: Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Got line: Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Got line: HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Got line: Upgrade: h2c [2024-08-01T01:21:44.554Z] Got line: User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] GET /http1/dummy/x/1 HTTP/1.1 [2024-08-01T01:21:44.554Z] Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Upgrade: h2c [2024-08-01T01:21:44.554Z] User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Sending back HTTP/1.1 200 OK [2024-08-01T01:21:44.554Z] Content-length: 0 [2024-08-01T01:21:44.554Z] Header8859: UÿU [2024-08-01T01:21:44.554Z] Connection: close [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Accepted: Socket[addr=/127.0.0.1,port=54122,localport=37231] [2024-08-01T01:21:44.554Z] Got line: GET /http1/dummy/x/3 HTTP/1.1 [2024-08-01T01:21:44.554Z] Got line: Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Got line: Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Got line: HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Got line: Upgrade: h2c [2024-08-01T01:21:44.554Z] Got line: User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] GET /http1/dummy/x/3 HTTP/1.1 [2024-08-01T01:21:44.554Z] Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Upgrade: h2c [2024-08-01T01:21:44.554Z] User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Sending back HTTP/1.1 200 OK [2024-08-01T01:21:44.554Z] Content-length: 0 [2024-08-01T01:21:44.554Z] Header8859: UÿU [2024-08-01T01:21:44.554Z] Connection: close [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Accepted: Socket[addr=/127.0.0.1,port=54124,localport=37231] [2024-08-01T01:21:44.554Z] Got line: GET /http1/dummy/x/2 HTTP/1.1 [2024-08-01T01:21:44.554Z] Got line: Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Got line: Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Got line: HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Got line: Upgrade: h2c [2024-08-01T01:21:44.554Z] Got line: User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] GET /http1/dummy/x/2 HTTP/1.1 [2024-08-01T01:21:44.554Z] Connection: Upgrade, HTTP2-Settings [2024-08-01T01:21:44.554Z] Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA [2024-08-01T01:21:44.554Z] Upgrade: h2c [2024-08-01T01:21:44.554Z] User-Agent: Java-http-client/21.0.5-beta [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Sending back HTTP/1.1 200 OK [2024-08-01T01:21:44.554Z] Content-length: 0 [2024-08-01T01:21:44.554Z] Header8859: UÿU [2024-08-01T01:21:44.554Z] Connection: close [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Got: (GET http://127.0.0.1:37231/http1/dummy/x/0) 200 [2024-08-01T01:21:44.554Z] Got: (GET http://127.0.0.1:37231/http1/dummy/x/1) 200 [2024-08-01T01:21:44.554Z] Got: (GET http://127.0.0.1:37231/http1/dummy/x/2) 200 [2024-08-01T01:21:44.554Z] Got: (GET http://127.0.0.1:37231/http1/dummy/x/3) 200 [2024-08-01T01:21:44.554Z] HttpClient: PASSED [2024-08-01T01:21:44.554Z] Testing with URLConnection [2024-08-01T01:21:44.554Z] Accepted: Socket[addr=/127.0.0.1,port=54130,localport=37231] [2024-08-01T01:21:44.554Z] Got line: GET /http1/dummy/x HTTP/1.1 [2024-08-01T01:21:44.554Z] Got line: User-Agent: Java/21.0.5-beta [2024-08-01T01:21:44.554Z] Got line: Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Got line: Accept: */* [2024-08-01T01:21:44.554Z] Got line: Connection: keep-alive [2024-08-01T01:21:44.554Z] GET /http1/dummy/x HTTP/1.1 [2024-08-01T01:21:44.554Z] User-Agent: Java/21.0.5-beta [2024-08-01T01:21:44.554Z] Host: 127.0.0.1:37231 [2024-08-01T01:21:44.554Z] Accept: */* [2024-08-01T01:21:44.554Z] Connection: keep-alive [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] Sending back HTTP/1.1 200 OK [2024-08-01T01:21:44.554Z] Content-length: 0 [2024-08-01T01:21:44.554Z] Header8859: UÿU [2024-08-01T01:21:44.554Z] Connection: close [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] [2024-08-01T01:21:44.554Z] URLConnection: PASSED [2024-08-01T01:21:44.554Z] test: DONE [2024-08-01T01:21:44.554Z] test ISO_8859_1_Test.test("http://127.0.0.1:37231/http1/dummy/x", false): success [2024-08-01T01:21:44.554Z] config ISO_8859_1_Test.beforeMethod(org.testng.TestRunner@375b214): success [2024-08-01T01:21:44.554Z] Request to http://127.0.0.1:44623/http1/server/x [2024-08-01T01:21:44.554Z] Timeout signalled after 1920 seconds [2024-08-01T01:21:44.554Z] STDERR: [2024-08-01T01:21:44.554Z] TestServer(1): accepting connections [2024-08-01T01:21:44.554Z] TestServer(2): accepting connections [2024-08-01T01:21:44.554Z] DEBUG: [MainThread] [146ms] HttpClientImpl(1) proxySelector is java.net.ProxySelector$StaticProxySelector@3dff03a0 (user-supplied=true) [2024-08-01T01:21:44.554Z] DEBUG: [MainThread] [226ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:37231/http1/dummy/x/0 GET [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-1] [415ms] Exchange establishing exchange for http://127.0.0.1:37231/http1/dummy/x/0 GET, [2024-08-01T01:21:44.554Z] proxy=null [2024-08-01T01:21:44.554Z] DEBUG: [MainThread] [420ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:37231/http1/dummy/x/1 GET [2024-08-01T01:21:44.554Z] DEBUG: [MainThread] [443ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:37231/http1/dummy/x/2 GET [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-3] [453ms] Exchange establishing exchange for http://127.0.0.1:37231/http1/dummy/x/2 GET, [2024-08-01T01:21:44.554Z] proxy=null [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-2] [453ms] Exchange establishing exchange for http://127.0.0.1:37231/http1/dummy/x/1 GET, [2024-08-01T01:21:44.554Z] proxy=null [2024-08-01T01:21:44.554Z] DEBUG: [MainThread] [453ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:37231/http1/dummy/x/3 GET [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [474ms] Exchange establishing exchange for http://127.0.0.1:37231/http1/dummy/x/3 GET, [2024-08-01T01:21:44.554Z] proxy=null [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [559ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-3] [560ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-3] [560ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-3] [567ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-3] [567ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [560ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [573ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [573ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-1] [563ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-1] [575ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-2] [575ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-1] [575ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-2] [575ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-1] [576ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-2] [576ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-2] [577ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.554Z] DEBUG: [pool-1-thread-4] [628ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [629ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [633ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [634ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [636ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [637ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [641ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [642ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [730ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [731ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [735ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [735ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [737ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [737ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [735ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [741ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [780ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@5adb8173 queue.isEmpty: true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [780ms] Http1AsyncReceiver(SocketTube(2)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@5637aac7 queue.isEmpty: true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [780ms] Http1AsyncReceiver(SocketTube(4)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@7272b64c queue.isEmpty: true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [780ms] Http1AsyncReceiver(SocketTube(3)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@1f6379a5 queue.isEmpty: true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [875ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@5adb8173, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [876ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [881ms] Http1AsyncReceiver(SocketTube(2)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@5637aac7, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [882ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [875ms] Http1AsyncReceiver(SocketTube(3)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@1f6379a5, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [891ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [881ms] Http1AsyncReceiver(SocketTube(4)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@7272b64c, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [894ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [909ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [909ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [910ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [910ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [911ms] Http1Exchange response created in advance [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [911ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [910ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [915ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [919ms] Http1Exchange response created in advance [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [920ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [919ms] Http1AsyncReceiver(SocketTube(3)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [925ms] PlainHttpConnection(SocketTube(1)) registering connect event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [925ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [926ms] Http1AsyncReceiver(SocketTube(3)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [926ms] Http1Exchange response created in advance [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [937ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [938ms] PlainHttpConnection(SocketTube(3)) registering connect event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [926ms] PlainHttpConnection(SocketTube(4)) registering connect event [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [931ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@447c894 for 8 (true) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [934ms] Http1AsyncReceiver(SocketTube(2)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [943ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [944ms] Http1AsyncReceiver(SocketTube(2)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [944ms] Http1Exchange response created in advance [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [945ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [946ms] PlainHttpConnection(SocketTube(2)) registering connect event [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 3ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: finishing connect [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 4ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:54118 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 23ms] PlainHttpConnection(SocketTube(1)) finishConnect, setting connected=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 28ms] Http1Exchange SocketTube(1) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 29ms] SocketTube(1) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 31ms] SocketTube(1) read publisher got subscriber [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 32ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@695ff010 for 8 (true) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 32ms] SocketTube(1) registering subscribe event [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 33ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@303d1546 for 8 (true) [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 61ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@1d21fccb for 8 (true) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 63ms] SocketTube(1) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 63ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: finishing connect [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 64ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:54120 [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 64ms] PlainHttpConnection(SocketTube(2)) ConnectEvent: finishing connect [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 65ms] Http1Publisher(SocketTube(1)) got subscriber: SocketTube(1) [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 65ms] PlainHttpConnection(SocketTube(2)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:54124 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 65ms] SocketTube(1) subscribed for writing [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 66ms] PlainHttpConnection(SocketTube(2)) finishConnect, setting connected=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 67ms] PlainHttpConnection(SocketTube(4)) finishConnect, setting connected=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 68ms] Http1Exchange SocketTube(4) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 68ms] SocketTube(4) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 68ms] SocketTube(4) read publisher got subscriber [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 69ms] SocketTube(4) registering subscribe event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 69ms] SocketTube(4) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 70ms] Http1Publisher(SocketTube(4)) got subscriber: SocketTube(4) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 70ms] SocketTube(4) subscribed for writing [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 71ms] SocketTube(4) write: registering startSubscription event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-2] [1s 71ms] Http1Exchange requestAction.headers [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 67ms] Http1Exchange SocketTube(2) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 68ms] SocketTube(1) write: registering startSubscription event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 73ms] SocketTube(2) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 74ms] SocketTube(2) read publisher got subscriber [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 75ms] SocketTube(2) registering subscribe event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 75ms] SocketTube(2) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 76ms] Http1Publisher(SocketTube(2)) got subscriber: SocketTube(2) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 77ms] SocketTube(2) subscribed for writing [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 77ms] SocketTube(2) write: registering startSubscription event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-4] [1s 78ms] Http1Exchange requestAction.headers [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 66ms] PlainHttpConnection(SocketTube(3)) ConnectEvent: finishing connect [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-3] [1s 74ms] Http1Exchange requestAction.headers [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 88ms] PlainHttpConnection(SocketTube(3)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:54122 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 89ms] PlainHttpConnection(SocketTube(3)) finishConnect, setting connected=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 89ms] Http1Exchange SocketTube(3) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 90ms] SocketTube(3) connecting flows [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 90ms] SocketTube(3) read publisher got subscriber [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 91ms] SocketTube(3) registering subscribe event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 91ms] SocketTube(3) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 92ms] Http1Publisher(SocketTube(3)) got subscriber: SocketTube(3) [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 92ms] SocketTube(3) subscribed for writing [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 93ms] SocketTube(3) write: registering startSubscription event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-1] [1s 93ms] Http1Exchange requestAction.headers [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 89ms] SocketTube(1) subscribe event raised [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 102ms] SocketTube(1) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@5f42c79f [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 102ms] SocketTube(1) read demand reset to 0 [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 106ms] SocketTube(1) calling onSubscribe [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 106ms] Http1AsyncReceiver(SocketTube(1)) Received onSubscribed from upstream [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 124ms] SocketTube(1) onSubscribe called [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 124ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 124ms] SocketTube(1) pending subscriber subscribed [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 125ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 125ms] SocketTube(4) subscribe event raised [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 125ms] SocketTube(4) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@420b172 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 126ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: requesting one more from upstream [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 126ms] SocketTube(1) got some demand for reading [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 127ms] SocketTube(1) resuming read event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 131ms] SocketTube(1) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 126ms] SocketTube(4) read demand reset to 0 [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 133ms] SocketTube(4) calling onSubscribe [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 133ms] Http1AsyncReceiver(SocketTube(4)) Received onSubscribed from upstream [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 134ms] SocketTube(4) onSubscribe called [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 134ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 135ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 135ms] Http1AsyncReceiver(SocketTube(4)) Http1TubeSubscriber: requesting one more from upstream [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 135ms] SocketTube(4) got some demand for reading [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 135ms] SocketTube(4) resuming read event [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 136ms] SocketTube(4) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 134ms] SocketTube(4) pending subscriber subscribed [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 141ms] SocketTube(4) write: starting subscription [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 141ms] SocketTube(4) write: offloading requestMore [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 144ms] SocketTube(1) write: starting subscription [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 144ms] SocketTube(4) write: requesting more... [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 144ms] SocketTube(1) write: offloading requestMore [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 145ms] Http1Publisher(SocketTube(4)) subscription request(1), demand=1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-5] [1s 145ms] Http1Publisher(SocketTube(4)) WriteTask [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-6] [1s 146ms] SocketTube(1) write: requesting more... [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-6] [1s 146ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1 [2024-08-01T01:21:44.555Z] DEBUG: [pool-1-thread-6] [1s 147ms] Http1Publisher(SocketTube(1)) WriteTask [2024-08-01T01:21:44.555Z] DEBUG: [HttpClient-1-SelectorManager] [1s 145ms] SocketTube(2) subscribe event raised [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 149ms] SocketTube(2) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@19156afb [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 150ms] SocketTube(2) read demand reset to 0 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 150ms] SocketTube(2) calling onSubscribe [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 150ms] Http1AsyncReceiver(SocketTube(2)) Received onSubscribed from upstream [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 166ms] SocketTube(2) onSubscribe called [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 166ms] SocketTube(2) pending subscriber subscribed [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 167ms] SocketTube(2) write: starting subscription [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 167ms] SocketTube(2) write: offloading requestMore [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 168ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 181ms] Http1AsyncReceiver(SocketTube(2)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 181ms] Http1AsyncReceiver(SocketTube(2)) Http1TubeSubscriber: requesting one more from upstream [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 182ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6b9e1183 for 1 (true) [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 182ms] SocketTube(2) got some demand for reading [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 182ms] SocketTube(2) resuming read event [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 182ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3e2a67ad for 1 (true) [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 183ms] SocketTube(3) subscribe event raised [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 184ms] SocketTube(3) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@76136e78 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 184ms] SocketTube(2) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 184ms] SocketTube(3) read demand reset to 0 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 185ms] SocketTube(3) calling onSubscribe [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 185ms] Http1AsyncReceiver(SocketTube(3)) Received onSubscribed from upstream [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 185ms] SocketTube(3) onSubscribe called [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 186ms] SocketTube(3) pending subscriber subscribed [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 186ms] SocketTube(3) write: starting subscription [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 186ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 186ms] SocketTube(3) write: offloading requestMore [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-8] [1s 186ms] SocketTube(2) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 187ms] Http1AsyncReceiver(SocketTube(3)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 188ms] Http1AsyncReceiver(SocketTube(3)) Http1TubeSubscriber: requesting one more from upstream [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 189ms] SocketTube(3) got some demand for reading [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 189ms] SocketTube(3) resuming read event [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-7] [1s 193ms] SocketTube(3) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-8] [1s 188ms] Http1Publisher(SocketTube(2)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-8] [1s 197ms] Http1Publisher(SocketTube(2)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 206ms] SocketTube(3) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 206ms] Http1Publisher(SocketTube(3)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 206ms] Http1Publisher(SocketTube(3)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 206ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@354c4c93 for 1 (true) [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 209ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@66273db8 for 1 (true) [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-5] [1s 217ms] Http1Publisher(SocketTube(4)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-5] [1s 218ms] SocketTube(4) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-8] [1s 218ms] Http1Publisher(SocketTube(2)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-8] [1s 219ms] SocketTube(2) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-6] [1s 225ms] Http1Publisher(SocketTube(1)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-6] [1s 226ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 227ms] Http1Publisher(SocketTube(3)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 227ms] SocketTube(3) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Http1Request headers [2024-08-01T01:21:44.556Z] INFO: REQUEST: http://127.0.0.1:37231/http1/dummy/x/0 GET [2024-08-01T01:21:44.556Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Http1Request headers [2024-08-01T01:21:44.556Z] INFO: REQUEST: http://127.0.0.1:37231/http1/dummy/x/2 GET [2024-08-01T01:21:44.556Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Http1Request headers [2024-08-01T01:21:44.556Z] INFO: REQUEST: http://127.0.0.1:37231/http1/dummy/x/1 GET [2024-08-01T01:21:44.556Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Http1Request headers [2024-08-01T01:21:44.556Z] INFO: REQUEST: http://127.0.0.1:37231/http1/dummy/x/3 GET [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 341ms] Http1Exchange setting outgoing with headers [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 345ms] Http1Exchange setting outgoing with headers [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 346ms] Http1Exchange setting outgoing with headers [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 346ms] Http1Exchange setting outgoing with headers [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 354ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 356ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 354ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 354ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 357ms] Http1Publisher(SocketTube(2)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 365ms] Http1Publisher(SocketTube(1)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 365ms] Http1Publisher(SocketTube(4)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 366ms] Http1Publisher(SocketTube(3)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 366ms] Http1Publisher(SocketTube(2)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 366ms] Http1Publisher(SocketTube(1)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 367ms] Http1Publisher(SocketTube(4)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 367ms] Http1Publisher(SocketTube(3)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 368ms] Http1Exchange initiating completion of headersSentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 368ms] Http1Exchange initiating completion of headersSentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 368ms] Http1Exchange initiating completion of headersSentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 369ms] Http1Exchange initiating completion of headersSentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 372ms] Http1Publisher(SocketTube(2)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 372ms] Http1Publisher(SocketTube(3)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 376ms] Http1Publisher(SocketTube(2)) onNext with 207 bytes [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 376ms] Http1Publisher(SocketTube(3)) onNext with 207 bytes [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 376ms] Http1Publisher(SocketTube(1)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 376ms] SocketTube(3) trying to write: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 377ms] Http1Publisher(SocketTube(4)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=207 cap=207]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 377ms] Http1Publisher(SocketTube(4)) onNext with 207 bytes [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 378ms] SocketTube(4) trying to write: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 376ms] SocketTube(2) trying to write: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 377ms] Http1Publisher(SocketTube(1)) onNext with 207 bytes [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 381ms] SocketTube(3) wrote: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 381ms] SocketTube(4) wrote: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 382ms] SocketTube(2) wrote: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 382ms] SocketTube(1) trying to write: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 383ms] SocketTube(3) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 384ms] Http1Publisher(SocketTube(3)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 384ms] SocketTube(3) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 385ms] SocketTube(3) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 383ms] SocketTube(4) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 385ms] Http1Publisher(SocketTube(4)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 386ms] SocketTube(4) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 386ms] SocketTube(4) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 386ms] Http1Publisher(SocketTube(4)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 387ms] Http1Publisher(SocketTube(4)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 388ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 388ms] Exchange sendRequestBody [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 388ms] Http1Exchange sendBodyAsync [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 389ms] Http1Exchange bodySubscriber is null [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 384ms] SocketTube(1) wrote: 207 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 385ms] Http1Publisher(SocketTube(3)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 389ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 390ms] Http1Publisher(SocketTube(3)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 389ms] SocketTube(1) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 390ms] Http1Publisher(SocketTube(4)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 390ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 391ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 391ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 391ms] Http1Publisher(SocketTube(1)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 392ms] Http1Publisher(SocketTube(1)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 392ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 392ms] Exchange sendRequestBody [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 392ms] Http1Exchange sendBodyAsync [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 390ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 397ms] Http1Exchange bodySubscriber is null [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 398ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 398ms] Http1Publisher(SocketTube(1)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 399ms] Http1Publisher(SocketTube(1)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 400ms] Http1Exchange initiating completion of bodySentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 390ms] Http1Publisher(SocketTube(4)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 395ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6b9e1183 for 0 (false) [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 395ms] SocketTube(2) write: requesting more... [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 397ms] Exchange sendRequestBody [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 403ms] Http1Exchange sendBodyAsync [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 403ms] Http1Publisher(SocketTube(2)) subscription request(1), demand=1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 404ms] SocketTube(2) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 404ms] SocketTube(2) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 405ms] Http1Publisher(SocketTube(2)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 407ms] Http1Publisher(SocketTube(2)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 408ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 408ms] Exchange sendRequestBody [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 408ms] Http1Exchange sendBodyAsync [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 409ms] Http1Publisher(SocketTube(1)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 403ms] Http1Exchange initiating completion of bodySentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 404ms] Http1Exchange bodySubscriber is null [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 407ms] SocketTube(1) read bytes: 74 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 409ms] Http1Exchange bodySubscriber is null [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 413ms] Http1Publisher(SocketTube(1)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@4763a6e [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 413ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 414ms] Http1AsyncReceiver(SocketTube(1)) Putting 74 bytes into the queue [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 414ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 413ms] Http1Publisher(SocketTube(4)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 415ms] Http1Publisher(SocketTube(3)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 416ms] Http1Publisher(SocketTube(4)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@1bfe24ea [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 415ms] SocketTube(1) resuming read event [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 416ms] Http1AsyncReceiver(SocketTube(1)) Got 74 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@5adb8173 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 418ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6b9e1183 for 1 (false) [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 416ms] Http1Publisher(SocketTube(2)) WriteTask [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 416ms] Http1Publisher(SocketTube(3)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 418ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-9] [1s 419ms] Http1AsyncReceiver(SocketTube(1)) Forwarding 74 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@5adb8173 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-2] [1s 420ms] Http1Exchange sendBodyAsync completed successfully [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 418ms] SocketTube(1) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 423ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6b9e1183 for 0 (false) [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 423ms] SocketTube(1) no more demand for reading [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 424ms] SocketTube(1) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-3] [1s 424ms] Http1Exchange sendBodyAsync completed successfully [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 424ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3e2a67ad for 0 (false) [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 418ms] Http1Publisher(SocketTube(2)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.556Z] DEBUG: [HttpClient-1-SelectorManager] [1s 426ms] SocketTube(4) read bytes: 74 [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 426ms] Http1Exchange initiating completion of bodySentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 419ms] Http1Exchange initiating completion of bodySentCF [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 426ms] Http1Publisher(SocketTube(2)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-1] [1s 426ms] Http1Publisher(SocketTube(3)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.556Z] DEBUG: [pool-1-thread-4] [1s 427ms] Http1Publisher(SocketTube(2)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@474a1f70 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 427ms] Http1Exchange sendBodyAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 428ms] Http1Exchange reading headers [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 426ms] Http1AsyncReceiver(SocketTube(4)) Putting 74 bytes into the queue [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 427ms] Http1Publisher(SocketTube(3)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@7fa0e1b1 [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 429ms] SocketTube(4) resuming read event [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 429ms] Http1Exchange sendBodyAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 429ms] Http1AsyncReceiver(SocketTube(4)) Got 74 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@7272b64c [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 430ms] Http1Exchange reading headers [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 430ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1 [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 430ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3e2a67ad for 1 (false) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 431ms] Http1AsyncReceiver(SocketTube(4)) Forwarding 74 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@7272b64c [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 431ms] SocketTube(4) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-3] [1s 432ms] Http1Exchange reading headers [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 445ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3e2a67ad for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 446ms] SocketTube(4) no more demand for reading [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 446ms] SocketTube(4) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 449ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@66273db8 for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 446ms] Http1Exchange reading headers [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 458ms] SocketTube(3) read bytes: 74 [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 458ms] Http1AsyncReceiver(SocketTube(3)) Putting 74 bytes into the queue [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 459ms] Http1AsyncReceiver(SocketTube(3)) Got 74 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@1f6379a5 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 459ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 460ms] Http1AsyncReceiver(SocketTube(3)) Forwarding 74 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@1f6379a5 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 465ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Sending 74/74 bytes to header parser [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 465ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Reading Headers: (remaining: 0) READING_HEADERS [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 465ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) First time around [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-3] [1s 465ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: (remaining: 74) READING_HEADERS [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-3] [1s 466ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) First time around [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-3] [1s 467ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) headersReader is not yet completed [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 470ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Parsing headers completed. bytes=74 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 470ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Sending 74/74 bytes to header parser [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 471ms] Http1AsyncReceiver(SocketTube(3)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@1f6379a5 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 471ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Parsing headers completed. bytes=74 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 472ms] Http1AsyncReceiver(SocketTube(4)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@7272b64c [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 466ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) headersReader is not yet completed [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 474ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Reading Headers: creating Response object; state is now READING_BODY [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 474ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Reading Headers: (remaining: 0) READING_HEADERS [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 474ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) First time around [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 475ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) headersReader is already completed [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 475ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Reading Headers: creating Response object; state is now READING_BODY [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 476ms] Http1Exchange getResponseAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 476ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Reading Headers: (remaining: 0) READING_HEADERS [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 476ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) First time around [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 476ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) headersReader is not yet completed [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 477ms] SocketTube(3) resuming read event [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 477ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@66273db8 for 1 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 478ms] SocketTube(3) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 479ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@354c4c93 for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 480ms] SocketTube(2) read bytes: 74 [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 480ms] Http1AsyncReceiver(SocketTube(2)) Putting 74 bytes into the queue [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 475ms] Http1Exchange getResponseAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 488ms] SocketTube(2) resuming read event [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 488ms] Http1AsyncReceiver(SocketTube(2)) Got 74 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@5637aac7 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 488ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 489ms] Http1AsyncReceiver(SocketTube(2)) Forwarding 74 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@5637aac7 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 489ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Sending 74/74 bytes to header parser [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 485ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Sending 74/74 bytes to header parser [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 490ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Parsing headers completed. bytes=74 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 491ms] Http1AsyncReceiver(SocketTube(2)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@5637aac7 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 491ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Reading Headers: creating Response object; state is now READING_BODY [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 491ms] Http1Exchange getResponseAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 488ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@354c4c93 for 1 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 497ms] SocketTube(2) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 498ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@66273db8 for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 498ms] SocketTube(3) no more demand for reading [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 499ms] SocketTube(3) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 491ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Parsing headers completed. bytes=74 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 500ms] Http1AsyncReceiver(SocketTube(1)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@5adb8173 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 501ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: creating Response object; state is now READING_BODY [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 501ms] Http1Exchange getResponseAsync completed successfully [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 500ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@354c4c93 for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 506ms] SocketTube(2) no more demand for reading [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 506ms] SocketTube(2) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.557Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Exchange lambda$wrapForLog$12 [2024-08-01T01:21:44.557Z] INFO: RESPONSE: (GET http://127.0.0.1:37231/http1/dummy/x/3) 200 HTTP_1_1 Local port: 54122 [2024-08-01T01:21:44.557Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Exchange lambda$wrapForLog$12 [2024-08-01T01:21:44.557Z] INFO: RESPONSE: (GET http://127.0.0.1:37231/http1/dummy/x/0) 200 HTTP_1_1 Local port: 54118 [2024-08-01T01:21:44.557Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Exchange lambda$wrapForLog$12 [2024-08-01T01:21:44.557Z] INFO: RESPONSE: (GET http://127.0.0.1:37231/http1/dummy/x/2) 200 HTTP_1_1 Local port: 54124 [2024-08-01T01:21:44.557Z] Aug 01, 2024 12:49:52 AM jdk.internal.net.http.Exchange lambda$wrapForLog$12 [2024-08-01T01:21:44.557Z] INFO: RESPONSE: (GET http://127.0.0.1:37231/http1/dummy/x/1) 200 HTTP_1_1 Local port: 54120 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-5] [1s 641ms] Http1AsyncReceiver(SocketTube(2)) Delegate done: 0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-8] [1s 643ms] Http1AsyncReceiver(SocketTube(3)) Delegate done: 0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 652ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) readBody: return2Cache: true [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-6] [1s 653ms] Http1AsyncReceiver(SocketTube(4)) Delegate done: 0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 654ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) readBody: return2Cache: true [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 660ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) readBody: return2Cache: true [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 654ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) readBody: return2Cache: true [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 741ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 743ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 745ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 746ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 758ms] Http1AsyncReceiver(SocketTube(2)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd queue.isEmpty: false [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 759ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb queue.isEmpty: false [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 758ms] Http1AsyncReceiver(SocketTube(4)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f queue.isEmpty: false [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 778ms] Http1AsyncReceiver(SocketTube(3)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35 queue.isEmpty: false [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 781ms] PlainHttpConnection(SocketTube(4))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Exchange$Http1ResponseBodySubscriber [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 782ms] PlainHttpConnection(SocketTube(2))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Exchange$Http1ResponseBodySubscriber [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 783ms] HttpClientImpl(1) body subscriber registered: 1 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 784ms] HttpClientImpl(1) body subscriber registered: 2 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 784ms] PlainHttpConnection(SocketTube(3))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Exchange$Http1ResponseBodySubscriber [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 784ms] HttpClientImpl(1) body subscriber registered: 3 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 790ms] Http1AsyncReceiver(SocketTube(4)) cleared [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-2] [1s 791ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) SocketTube(4): return to HTTP/1.1 pool [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 797ms] Http1AsyncReceiver(SocketTube(3)) cleared [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 797ms] Http1AsyncReceiver(SocketTube(2)) cleared [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 797ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) SocketTube(3): return to HTTP/1.1 pool [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 797ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) SocketTube(2): return to HTTP/1.1 pool [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 799ms] PlainHttpConnection(SocketTube(2)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 799ms] Http1AsyncReceiver(SocketTube(1)) Delegate done: 0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 800ms] PlainHttpConnection(SocketTube(1))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Exchange$Http1ResponseBodySubscriber [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 799ms] PlainHttpConnection(SocketTube(3)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 801ms] SocketTube(2) signal read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 805ms] HttpClientImpl(1) body subscriber registered: 4 [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 806ms] SocketTube(3) signal read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 806ms] Http1AsyncReceiver(SocketTube(1)) cleared [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 806ms] SocketTube(2) got read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 807ms] SocketTube(2) pausing read event [2024-08-01T01:21:44.557Z] DEBUG: [HttpClient-1-SelectorManager] [1s 810ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@354c4c93 for 0 (false) [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-1] [1s 806ms] SocketTube(3) got read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 806ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) SocketTube(1): return to HTTP/1.1 pool [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-4] [1s 810ms] SocketTube(2) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@19156afb [2024-08-01T01:21:44.557Z] DEBUG: [pool-1-thread-9] [1s 814ms] PlainHttpConnection(SocketTube(1)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-4] [1s 815ms] SocketTube(2) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-4] [1s 815ms] Http1AsyncReceiver(SocketTube(2)) onError: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-1] [1s 813ms] SocketTube(3) pausing read event [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 815ms] SocketTube(1) signal read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 815ms] SocketTube(2) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 822ms] SocketTube(1) got read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 822ms] SocketTube(1) pausing read event [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 822ms] SocketTube(2) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@405de1c7 (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 823ms] SocketTube(2) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 824ms] HttpClientImpl(1) Got java.nio.channels.ClosedChannelException while handling registration events [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 825ms] PlainHttpConnection(SocketTube(4)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 833ms] SocketTube(4) signal read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 835ms] SocketTube(4) got read error: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 835ms] SocketTube(4) pausing read event [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 836ms] SocketTube(2) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-1] [1s 836ms] SocketTube(3) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@76136e78 [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 837ms] SocketTube(2) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@405de1c7 (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 836ms] SocketTube(1) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@5f42c79f [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-1] [1s 838ms] SocketTube(3) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 838ms] SocketTube(1) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 838ms] SocketTube(2) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-1] [1s 838ms] Http1AsyncReceiver(SocketTube(3)) onError: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 838ms] Http1AsyncReceiver(SocketTube(1)) onError: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 839ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@66273db8 for 0 (false) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 839ms] SocketTube(3) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 840ms] SocketTube(3) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@70370f9b (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 840ms] SocketTube(3) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 841ms] HttpClientImpl(1) Got java.nio.channels.ClosedChannelException while handling registration events [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 841ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6b9e1183 for 0 (false) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 842ms] SocketTube(1) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 842ms] SocketTube(1) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@2c0da0ff (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 843ms] SocketTube(1) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 843ms] HttpClientImpl(1) Got java.nio.channels.ClosedChannelException while handling registration events [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 844ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3e2a67ad for 0 (false) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 844ms] SocketTube(4) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 845ms] SocketTube(4) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@420b172 [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 845ms] SocketTube(4) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 846ms] Http1AsyncReceiver(SocketTube(4)) onError: java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 861ms] SocketTube(4) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@669bb3d (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 862ms] SocketTube(4) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 862ms] HttpClientImpl(1) Got java.nio.channels.ClosedChannelException while handling registration events [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 862ms] SocketTube(3) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 863ms] SocketTube(3) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@70370f9b (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 863ms] SocketTube(3) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 864ms] SocketTube(1) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 864ms] SocketTube(1) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@2c0da0ff (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 864ms] SocketTube(1) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 865ms] SocketTube(4) ReadEvent abort: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 866ms] SocketTube(4) signalError to jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription@669bb3d (java.nio.channels.ClosedChannelException) [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-1] [1s 866ms] Http1AsyncReceiver(SocketTube(3)) recorded java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] delegate: null [2024-08-01T01:21:44.558Z] queue.isEmpty: false [2024-08-01T01:21:44.558Z] stopRequested: false java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-9] [1s 866ms] Http1AsyncReceiver(SocketTube(1)) recorded java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] delegate: null [2024-08-01T01:21:44.558Z] queue.isEmpty: false [2024-08-01T01:21:44.558Z] stopRequested: false java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:428) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:406) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpConnection.closeOrReturnToCache(HttpConnection.java:414) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.onFinished(Http1Response.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.ResponseContent$FixedLengthBodyParser.onSubscribe(ResponseContent.java:565) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response$BodyReader.onSubscribe(Http1Response.java:690) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.handlePendingDelegate(Http1AsyncReceiver.java:395) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:214) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:182) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$TryEndDeferredCompleter.complete(SequentialScheduler.java:324) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:151) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:207) [2024-08-01T01:21:44.558Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.558Z] at java.base/java.lang.Thread.run(Thread.java:1583) [2024-08-01T01:21:44.558Z] DEBUG: [HttpClient-1-SelectorManager] [1s 873ms] SocketTube(4) signal read error: java.nio.channels.ClosedChannelException [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-4] [1s 875ms] Http1AsyncReceiver(SocketTube(2)) recorded java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] delegate: null [2024-08-01T01:21:44.558Z] queue.isEmpty: false [2024-08-01T01:21:44.558Z] stopRequested: false java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:428) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:406) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpConnection.closeOrReturnToCache(HttpConnection.java:414) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.onFinished(Http1Response.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.ResponseContent$FixedLengthBodyParser.onSubscribe(ResponseContent.java:565) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response$BodyReader.onSubscribe(Http1Response.java:690) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.handlePendingDelegate(Http1AsyncReceiver.java:395) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:214) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:182) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:207) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:280) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:233) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.subscribe(Http1AsyncReceiver.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.lambda$readBody$3(Http1Response.java:361) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:177) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.readBody(Http1Response.java:325) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Exchange.readBodyAsync(Http1Exchange.java:452) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Exchange.readBodyAsync(Exchange.java:220) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.MultiExchange.lambda$responseAsync0$4(MultiExchange.java:358) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) [2024-08-01T01:21:44.558Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.558Z] at java.base/java.lang.Thread.run(Thread.java:1583) [2024-08-01T01:21:44.558Z] java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:428) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:406) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpConnection.closeOrReturnToCache(HttpConnection.java:414) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.onFinished(Http1Response.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.ResponseContent$FixedLengthBodyParser.onSubscribe(ResponseContent.java:565) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response$BodyReader.onSubscribe(Http1Response.java:690) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.handlePendingDelegate(Http1AsyncReceiver.java:395) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:214) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:182) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:207) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:280) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:233) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.subscribe(Http1AsyncReceiver.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.lambda$readBody$3(Http1Response.java:361) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:177) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.readBody(Http1Response.java:325) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Exchange.readBodyAsync(Http1Exchange.java:452) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Exchange.readBodyAsync(Exchange.java:220) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.MultiExchange.lambda$responseAsync0$4(MultiExchange.java:358) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) [2024-08-01T01:21:44.558Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.558Z] at java.base/java.lang.Thread.run(Thread.java:1583) [2024-08-01T01:21:44.558Z] DEBUG: [pool-1-thread-2] [1s 886ms] Http1AsyncReceiver(SocketTube(4)) recorded java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] delegate: null [2024-08-01T01:21:44.558Z] queue.isEmpty: false [2024-08-01T01:21:44.558Z] stopRequested: false java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] java.io.IOException: connection closed locally [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:428) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:406) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpConnection.closeOrReturnToCache(HttpConnection.java:414) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.onFinished(Http1Response.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.ResponseContent$FixedLengthBodyParser.onSubscribe(ResponseContent.java:565) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response$BodyReader.onSubscribe(Http1Response.java:690) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.handlePendingDelegate(Http1AsyncReceiver.java:395) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:214) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:182) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:207) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:280) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:233) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.subscribe(Http1AsyncReceiver.java:436) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.lambda$readBody$3(Http1Response.java:361) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:177) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Response.readBody(Http1Response.java:325) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Http1Exchange.readBodyAsync(Http1Exchange.java:452) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.Exchange.readBodyAsync(Exchange.java:220) [2024-08-01T01:21:44.558Z] at java.net.http/jdk.internal.net.http.MultiExchange.lambda$responseAsync0$4(MultiExchange.java:358) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) [2024-08-01T01:21:44.558Z] at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) [2024-08-01T01:21:44.559Z] at ISO_8859_1_Test$TestExecutor.lambda$execute$0(ISO_8859_1_Test.java:154) [2024-08-01T01:21:44.559Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) [2024-08-01T01:21:44.559Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) [2024-08-01T01:21:44.559Z] at java.base/java.lang.Thread.run(Thread.java:1583) [2024-08-01T01:21:44.559Z] Aug 01, 2024 12:49:53 AM jdk.internal.net.http.Http1AsyncReceiver onReadError [2024-08-01T01:21:44.559Z] INFO: ERROR: HTTP/1 read subscriber recorded error: <uri unavailable> - java.io.IOException: connection closed locally [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 911ms] SocketTube(2) Stopping read scheduler [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 912ms] SocketTube(2) leaving read() loop with error: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 912ms] SocketTube(2) Read scheduler stopped [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 915ms] HttpClientImpl(1) body subscriber unregistered: 3 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 916ms] Http1AsyncReceiver(SocketTube(2)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=false [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 916ms] Http1AsyncReceiver(SocketTube(2)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 917ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 917ms] Http1AsyncReceiver(SocketTube(2)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 918ms] Http1AsyncReceiver(SocketTube(2)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 918ms] Http1AsyncReceiver(SocketTube(2)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd [2024-08-01T01:21:44.559Z] Aug 01, 2024 12:49:53 AM jdk.internal.net.http.Http1AsyncReceiver onReadError [2024-08-01T01:21:44.559Z] INFO: ERROR: HTTP/1 read subscriber recorded error: <uri unavailable> - java.io.IOException: connection closed locally [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 920ms] SocketTube(1) Stopping read scheduler [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 920ms] SocketTube(1) leaving read() loop with error: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 920ms] SocketTube(1) Read scheduler stopped [2024-08-01T01:21:44.559Z] Aug 01, 2024 12:49:53 AM jdk.internal.net.http.Http1AsyncReceiver onReadError [2024-08-01T01:21:44.559Z] INFO: ERROR: HTTP/1 read subscriber recorded error: <uri unavailable> - java.io.IOException: connection closed locally [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 921ms] SocketTube(4) Stopping read scheduler [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 922ms] SocketTube(4) leaving read() loop with error: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 922ms] SocketTube(4) Read scheduler stopped [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 922ms] HttpClientImpl(1) body subscriber unregistered: 1 [2024-08-01T01:21:44.559Z] Aug 01, 2024 12:49:53 AM jdk.internal.net.http.Http1AsyncReceiver onReadError [2024-08-01T01:21:44.559Z] INFO: ERROR: HTTP/1 read subscriber recorded error: <uri unavailable> - java.io.IOException: connection closed locally [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 923ms] SocketTube(3) Stopping read scheduler [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 923ms] SocketTube(3) leaving read() loop with error: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 924ms] SocketTube(3) Read scheduler stopped [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 924ms] HttpClientImpl(1) body subscriber unregistered: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 925ms] Http1AsyncReceiver(SocketTube(3)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=false [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 925ms] Http1AsyncReceiver(SocketTube(3)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 926ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 926ms] Http1AsyncReceiver(SocketTube(3)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 927ms] Http1AsyncReceiver(SocketTube(3)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 927ms] Http1AsyncReceiver(SocketTube(3)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 928ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 928ms] Http1AsyncReceiver(SocketTube(3)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@6cfb6bfe/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@5947ae35 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 928ms] Http1AsyncReceiver(SocketTube(3)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 929ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Finished reading body: READING_BODY [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 930ms] Http1Response(id=4, PlainHttpConnection(SocketTube(3))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 919ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 921ms] HttpClientImpl(1) body subscriber unregistered: 2 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 935ms] Http1AsyncReceiver(SocketTube(2)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@46417cfd/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@444014bd [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 923ms] Http1AsyncReceiver(SocketTube(4)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=false [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 936ms] Http1AsyncReceiver(SocketTube(2)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 936ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Finished reading body: READING_BODY [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 936ms] Http1AsyncReceiver(SocketTube(4)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 937ms] Http1Response(id=2, PlainHttpConnection(SocketTube(2))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 937ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 937ms] Http1AsyncReceiver(SocketTube(4)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 938ms] Http1AsyncReceiver(SocketTube(4)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 938ms] Http1AsyncReceiver(SocketTube(4)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 939ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 939ms] Http1AsyncReceiver(SocketTube(4)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@6f82a1ee/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@b7c289f [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 940ms] Http1AsyncReceiver(SocketTube(4)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 940ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Finished reading body: READING_BODY [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 941ms] Http1Response(id=3, PlainHttpConnection(SocketTube(4))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [1s 980ms] HttpClientImpl(1) ClientImpl (async) elapsed 1494 millis for GET to http://127.0.0.1:37231/http1/dummy/x/3 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [1s 981ms] HttpClientImpl(1) ClientImpl (async) elapsed 1506 millis for GET to http://127.0.0.1:37231/http1/dummy/x/2 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 983ms] HttpClientImpl(1) ClientImpl (async) elapsed 1725 millis for GET to http://127.0.0.1:37231/http1/dummy/x/0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 998ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Finished reading body: READING_BODY [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 999ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@5a274ab9(1) [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [1s 999ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=false [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s] Http1AsyncReceiver(SocketTube(1)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 1ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 1ms] Http1AsyncReceiver(SocketTube(1)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 2ms] Http1AsyncReceiver(SocketTube(1)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 3ms] Http1AsyncReceiver(SocketTube(1)) Got 0 bytes for delegate jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 6ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 9223372036854775807 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [1s 996ms] HttpClientImpl(1) ClientImpl (async) elapsed 1529 millis for GET to http://127.0.0.1:37231/http1/dummy/x/1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 10ms] Http1AsyncReceiver(SocketTube(1)) Forwarding 0 bytes to delegate jdk.internal.net.http.Http1Response$BodyReader@28a743ba/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@612f4acb [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 10ms] Http1AsyncReceiver(SocketTube(1)) Delegate done: 0 [2024-08-01T01:21:44.559Z] DEBUG: [MainThread] [2s 232ms] HttpClientImpl(2) proxySelector is java.net.ProxySelector$StaticProxySelector@3dff03a0 (user-supplied=true) [2024-08-01T01:21:44.559Z] DEBUG: [MainThread] [2s 251ms] HttpClientImpl(2) ClientImpl (async) send http://127.0.0.1:44623/http1/server/x/0 GET [2024-08-01T01:21:44.559Z] DEBUG: [MainThread] [2s 253ms] HttpClientImpl(2) ClientImpl (async) send http://127.0.0.1:44623/http1/server/x/1 GET [2024-08-01T01:21:44.559Z] DEBUG: [MainThread] [2s 255ms] HttpClientImpl(2) ClientImpl (async) send http://127.0.0.1:44623/http1/server/x/2 GET [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 257ms] Exchange establishing exchange for http://127.0.0.1:44623/http1/server/x/1 GET, [2024-08-01T01:21:44.559Z] proxy=null [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 258ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 258ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 259ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 259ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 261ms] Exchange establishing exchange for http://127.0.0.1:44623/http1/server/x/0 GET, [2024-08-01T01:21:44.559Z] proxy=null [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 261ms] Exchange establishing exchange for http://127.0.0.1:44623/http1/server/x/2 GET, [2024-08-01T01:21:44.559Z] proxy=null [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 262ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 262ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 262ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 262ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 263ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 263ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 263ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 265ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 266ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 268ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 268ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 262ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 269ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 269ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 270ms] Http1AsyncReceiver(SocketTube(5)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@2d9513c6 queue.isEmpty: true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 270ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 273ms] Http1AsyncReceiver(SocketTube(5)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@2d9513c6, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 274ms] Http1AsyncReceiver(SocketTube(5)) downstream subscription demand is 1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 274ms] Http1AsyncReceiver(SocketTube(5)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 275ms] Http1AsyncReceiver(SocketTube(5)) downstream subscription demand is 1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 276ms] Http1AsyncReceiver(SocketTube(5)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 276ms] Http1Exchange response created in advance [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 278ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 280ms] PlainHttpConnection(SocketTube(5)) registering connect event [2024-08-01T01:21:44.559Z] DEBUG: [MainThread] [2s 271ms] HttpClientImpl(2) ClientImpl (async) send http://127.0.0.1:44623/http1/server/x/3 GET [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 271ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 273ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.559Z] DEBUG: [HttpClient-2-SelectorManager] [2s 281ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@449245c1 for 8 (true) [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 284ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.559Z] DEBUG: [HttpClient-2-SelectorManager] [2s 285ms] PlainHttpConnection(SocketTube(5)) ConnectEvent: finishing connect [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 285ms] Http1AsyncReceiver(SocketTube(6)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@595e08e2 queue.isEmpty: true [2024-08-01T01:21:44.559Z] DEBUG: [HttpClient-2-SelectorManager] [2s 285ms] PlainHttpConnection(SocketTube(5)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:38278 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 286ms] Http1AsyncReceiver(SocketTube(6)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@595e08e2, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 286ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 286ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 286ms] Http1AsyncReceiver(SocketTube(7)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@1931a76e queue.isEmpty: true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 287ms] Exchange establishing exchange for http://127.0.0.1:44623/http1/server/x/3 GET, [2024-08-01T01:21:44.559Z] proxy=null [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 288ms] Http2ClientImpl not found in connection pool [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 288ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 288ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 289ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 291ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-4] [2s 286ms] Http1AsyncReceiver(SocketTube(6)) downstream subscription demand is 1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 286ms] PlainHttpConnection(SocketTube(5)) finishConnect, setting connected=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 287ms] Http1AsyncReceiver(SocketTube(7)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@1931a76e, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-9] [2s 304ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 304ms] Http1Exchange SocketTube(5) connecting flows [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 304ms] Http1AsyncReceiver(SocketTube(7)) downstream subscription demand is 1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 305ms] SocketTube(5) connecting flows [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 305ms] Http1AsyncReceiver(SocketTube(7)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 305ms] SocketTube(5) read publisher got subscriber [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 305ms] SocketTube(5) registering subscribe event [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 305ms] Http1AsyncReceiver(SocketTube(7)) downstream subscription demand is 1 [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 306ms] SocketTube(5) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 306ms] Http1AsyncReceiver(SocketTube(7)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-1] [2s 306ms] Http1Exchange response created in advance [2024-08-01T01:21:44.559Z] DEBUG: [pool-1-thread-2] [2s 306ms] Http1Publisher(SocketTube(5)) got subscriber: SocketTube(5) [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 306ms] SocketTube(5) subscribe event raised [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 306ms] Http1AsyncReceiver(SocketTube(6)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 306ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 306ms] SocketTube(5) subscribed for writing [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 307ms] SocketTube(5) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@4e6a2eb1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 307ms] SocketTube(5) write: registering startSubscription event [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 307ms] SocketTube(5) read demand reset to 0 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 307ms] Http1Exchange requestAction.headers [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 307ms] SocketTube(5) calling onSubscribe [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 307ms] Http1AsyncReceiver(SocketTube(5)) Received onSubscribed from upstream [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 307ms] PlainHttpConnection(SocketTube(7)) registering connect event [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 307ms] SocketTube(5) onSubscribe called [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 308ms] SocketTube(5) pending subscriber subscribed [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 308ms] Http1AsyncReceiver(SocketTube(5)) downstream subscription demand is 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 308ms] Http1AsyncReceiver(SocketTube(5)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 309ms] Http1AsyncReceiver(SocketTube(5)) Http1TubeSubscriber: requesting one more from upstream [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 308ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@b68a918 for 8 (true) [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 309ms] SocketTube(5) got some demand for reading [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 310ms] SocketTube(5) write: starting subscription [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 310ms] SocketTube(5) resuming read event [2024-08-01T01:21:44.560Z] Aug 01, 2024 12:49:53 AM jdk.internal.net.http.Http1Request headers [2024-08-01T01:21:44.560Z] INFO: REQUEST: http://127.0.0.1:44623/http1/server/x/2 GET [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 310ms] SocketTube(5) write: offloading requestMore [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-6] [2s 310ms] SocketTube(5) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 311ms] SocketTube(5) write: requesting more... [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 311ms] PlainHttpConnection(SocketTube(7)) ConnectEvent: finishing connect [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 311ms] Http1Publisher(SocketTube(5)) subscription request(1), demand=1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 311ms] Http1Publisher(SocketTube(5)) WriteTask [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 311ms] Http1Exchange setting outgoing with headers [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 311ms] Http1Publisher(SocketTube(5)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 312ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=208 cap=208]], throwable=null] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 312ms] SocketTube(5) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 312ms] Http1Publisher(SocketTube(5)) WriteTask [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 312ms] Http1Publisher(SocketTube(5)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.560Z] DEBUG: [HttpClient-2-SelectorManager] [2s 311ms] PlainHttpConnection(SocketTube(7)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:38280 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 314ms] PlainHttpConnection(SocketTube(7)) finishConnect, setting connected=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 313ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 313ms] Http1AsyncReceiver(SocketTube(6)) downstream subscription demand is 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 316ms] Http1AsyncReceiver(SocketTube(6)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 316ms] Http1Exchange response created in advance [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 316ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 313ms] Http1Exchange initiating completion of headersSentCF [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 315ms] Http1Exchange SocketTube(7) connecting flows [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 317ms] Http1Publisher(SocketTube(5)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=208 cap=208]], throwable=null] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 315ms] Http1Exchange Sending headers only [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 317ms] SocketTube(7) connecting flows [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 318ms] SocketTube(7) read publisher got subscriber [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 319ms] Http1AsyncReceiver(SocketTube(8)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@5043816c queue.isEmpty: true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 319ms] Http1AsyncReceiver(SocketTube(8)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@5043816c, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 320ms] Http1AsyncReceiver(SocketTube(8)) downstream subscription demand is 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 320ms] Http1AsyncReceiver(SocketTube(8)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-4] [2s 317ms] PlainHttpConnection(SocketTube(6)) registering connect event [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 318ms] Http1Publisher(SocketTube(5)) onNext with 208 bytes [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-1] [2s 319ms] SocketTube(7) registering subscribe event [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 321ms] Http1AsyncReceiver(SocketTube(8)) downstream subscription demand is 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 322ms] Http1AsyncReceiver(SocketTube(8)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 322ms] Http1Exchange response created in advance [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 322ms] Http1Exchange initiating connect async [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-9] [2s 324ms] PlainHttpConnection(SocketTube(8)) registering connect event [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 321ms] SocketTube(5) trying to write: 208 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 337ms] SocketTube(5) wrote: 208 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 338ms] SocketTube(5) write: requesting more... [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 339ms] Http1Publisher(SocketTube(5)) subscription request(1), demand=1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 339ms] SocketTube(5) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 339ms] SocketTube(5) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 340ms] Http1Publisher(SocketTube(5)) WriteTask [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 340ms] Http1Publisher(SocketTube(5)) hasOutgoing = false, demand = 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 340ms] Exchange checkFor407: all clear [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 340ms] Exchange sendRequestBody [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 341ms] Http1Exchange sendBodyAsync [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 341ms] Http1Exchange bodySubscriber is null [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 341ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 341ms] Http1Publisher(SocketTube(5)) WriteTask [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 342ms] Http1Publisher(SocketTube(5)) hasOutgoing = true, demand = 1 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 342ms] Http1Exchange initiating completion of bodySentCF [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 352ms] Http1Publisher(SocketTube(5)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 352ms] Http1Publisher(SocketTube(5)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@30408540 [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 356ms] Http1Exchange sendBodyAsync completed successfully [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 357ms] Http1Exchange reading headers [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 358ms] Http1Response(id=5, PlainHttpConnection(SocketTube(5))) Reading Headers: (remaining: 0) READING_HEADERS [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 358ms] Http1Response(id=5, PlainHttpConnection(SocketTube(5))) First time around [2024-08-01T01:21:44.560Z] DEBUG: [pool-1-thread-2] [2s 358ms] Http1Response(id=5, PlainHttpConnection(SocketTube(5))) headersReader is not yet completed [2024-08-01T01:21:44.560Z] rerun: [2024-08-01T01:21:44.560Z] cd /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/scratch/0 && \ [2024-08-01T01:21:44.560Z] DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1001/bus \ [2024-08-01T01:21:44.560Z] DISPLAY=:0 \ [2024-08-01T01:21:44.560Z] HOME=/home/jenkins \ [2024-08-01T01:21:44.560Z] LANG=en_US.UTF-8 \ [2024-08-01T01:21:44.560Z] PATH=/bin:/usr/bin:/usr/sbin \ [2024-08-01T01:21:44.560Z] XDG_RUNTIME_DIR=/run/user/1001 \ [2024-08-01T01:21:44.560Z] XDG_SESSION_CLASS=user \ [2024-08-01T01:21:44.560Z] XDG_SESSION_ID=679 \ [2024-08-01T01:21:44.560Z] XDG_SESSION_TYPE=tty \ [2024-08-01T01:21:44.560Z] CLASSPATH=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/javatest.jar:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jvmtest/openjdk/jtreg/lib/jtreg.jar \ [2024-08-01T01:21:44.560Z] /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/java \ [2024-08-01T01:21:44.560Z] -Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2024-08-01T01:21:44.560Z] -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2024-08-01T01:21:44.560Z] -Dtest.compiler.opts= \ [2024-08-01T01:21:44.560Z] -Dtest.java.opts= \ [2024-08-01T01:21:44.560Z] -Dtest.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.560Z] -Dcompile.jdk=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image \ [2024-08-01T01:21:44.560Z] -Dtest.timeout.factor=16.0 \ [2024-08-01T01:21:44.560Z] -Dtest.nativepath=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-01T01:21:44.560Z] -Dtest.root=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2024-08-01T01:21:44.560Z] -Dtest.name=java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.560Z] -Dtest.file=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ISO_8859_1_Test.java \ [2024-08-01T01:21:44.560Z] -Dtest.src=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient \ [2024-08-01T01:21:44.560Z] -Dtest.src.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.560Z] -Dtest.classes=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d \ [2024-08-01T01:21:44.560Z] -Dtest.class.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.560Z] -Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/java/net/httpclient/ISO_8859_1_Test.d:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/lib:/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/classes/2/test/jdk/java/net/httpclient/lib \ [2024-08-01T01:21:44.560Z] -Dtest.modules='java.base/sun.net.www.http java.base/sun.net.www java.base/sun.net java.net.http/jdk.internal.net.http.common java.net.http/jdk.internal.net.http.frame java.net.http/jdk.internal.net.http.hpack java.logging jdk.httpserver' \ [2024-08-01T01:21:44.560Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2024-08-01T01:21:44.560Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2024-08-01T01:21:44.560Z] -ea \ [2024-08-01T01:21:44.560Z] -esa \ [2024-08-01T01:21:44.561Z] -Xmx512m \ [2024-08-01T01:21:44.561Z] -XX:-UseCompressedOops \ [2024-08-01T01:21:44.561Z] -Djava.awt.headless=true \ [2024-08-01T01:21:44.561Z] -Djava.library.path=/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-01T01:21:44.561Z] -Djdk.internal.httpclient.debug=true \ [2024-08-01T01:21:44.561Z] -Djdk.httpclient.HttpClient.log=requests,responses,errors \ [2024-08-01T01:21:44.561Z] com.sun.javatest.regtest.agent.MainWrapper /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work/java/net/httpclient/ISO_8859_1_Test.d/testng.0.jta java/net/httpclient/ISO_8859_1_Test.java false ISO_8859_1_Test [2024-08-01T01:21:44.561Z] [2024-08-01T01:21:44.561Z] TEST RESULT: Error. Program `/home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/jdkbinary/j2sdk-image/bin/java' timed out (timeout set to 1920000ms, elapsed time including timeout handling was 1921502ms). [2024-08-01T01:21:44.561Z] -------------------------------------------------- [2024-08-01T01:35:36.100Z] Test results: passed: 877; error: 1 [2024-08-01T01:36:21.130Z] Report written to /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/report/html/report.html [2024-08-01T01:36:21.130Z] Results written to /home/jenkins/workspace/Test_openjdk21_hs_extended.openjdk_riscv64_linux_testList_5/aqa-tests/TKG/output_17224669911891/jdk_net_1/work [2024-08-01T01:36:21.130Z] Error: Some tests failed or other problems occurred. [2024-08-01T01:36:21.130Z] ----------------------------------- [2024-08-01T01:36:21.130Z] jdk_net_1_FAILED [2024-08-01T01:36:21.130Z] ----------------------------------- [2024-08-01T01:36:21.130Z] [2024-08-01T01:36:21.130Z] TEST TEARDOWN: [2024-08-01T01:36:21.130Z] Nothing to be done for teardown. [2024-08-01T01:36:21.130Z] jdk_net_1 Finish Time: Thu Aug 1 01:36:20 2024 Epoch Time (ms): 1722476180837