jdk_net_1

[2024-08-10T07:35:32.343Z] Running test jdk_net_1 ... [2024-08-10T07:35:32.343Z] =============================================== [2024-08-10T07:35:32.343Z] jdk_net_1 Start Time: Sat Aug 10 07:35:31 2024 Epoch Time (ms): 1723275331510 [2024-08-10T07:35:32.343Z] variation: Mode650 [2024-08-10T07:35:32.343Z] JVM_OPTIONS: -XX:-UseCompressedOops [2024-08-10T07:35:32.343Z] { \ [2024-08-10T07:35:32.343Z] echo ""; echo "TEST SETUP:"; \ [2024-08-10T07:35:32.343Z] echo "Nothing to be done for setup."; \ [2024-08-10T07:35:32.343Z] mkdir -p "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1"; \ [2024-08-10T07:35:32.343Z] cd "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1"; \ [2024-08-10T07:35:32.343Z] echo ""; echo "TESTING:"; \ [2024-08-10T07:35:32.343Z] "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image/bin/java" -Xmx512m -jar "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../../jvmtest/openjdk/jtreg/lib/jtreg.jar" \ [2024-08-10T07:35:32.343Z] -agentvm -a -ea -esa -v:fail,error,time,nopass -retain:fail,error,*.dmp,javacore.*,heapdump.*,*.trc -ignore:quiet -timeoutFactor:8 -xml:verify -k:'!headful' -concurrency:3 -nativepath:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/openjdk-test-image/jdk/jtreg/native" -vmoptions:"-Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true" \ [2024-08-10T07:35:32.343Z] -w ""/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1"/work" \ [2024-08-10T07:35:32.343Z] -r ""/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1"/report" \ [2024-08-10T07:35:32.343Z] -jdk:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image" \ [2024-08-10T07:35:32.343Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk/ProblemList.txt" \ [2024-08-10T07:35:32.343Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../../jvmtest/openjdk/excludes/ProblemList_openjdk17.txt" \ [2024-08-10T07:35:32.343Z] \ [2024-08-10T07:35:32.343Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../openjdk/excludes/vendors/eclipse/ProblemList_openjdk17.txt" \ [2024-08-10T07:35:32.343Z] "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk:jdk_net"; \ [2024-08-10T07:35:32.343Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "jdk_net_1""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/..; else echo "-----------------------------------"; echo "jdk_net_1""_FAILED"; echo "-----------------------------------"; fi; \ [2024-08-10T07:35:32.344Z] echo ""; echo "TEST TEARDOWN:"; \ [2024-08-10T07:35:32.344Z] echo "Nothing to be done for teardown."; \ [2024-08-10T07:35:32.344Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/TestTargetResult"; [2024-08-10T07:35:32.344Z] [2024-08-10T07:35:32.344Z] TEST SETUP: [2024-08-10T07:35:32.344Z] Nothing to be done for setup. [2024-08-10T07:35:32.344Z] [2024-08-10T07:35:32.344Z] TESTING: [2024-08-10T07:35:33.140Z] Directory "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1/work" not found: creating [2024-08-10T07:35:33.140Z] Directory "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/../TKG/output_1723273565654/jdk_net_1/report" not found: creating [2024-08-10T07:35:47.899Z] XML output with verification to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work [2024-08-10T07:54:47.237Z] -------------------------------------------------- [2024-08-10T07:54:47.237Z] TEST: java/net/httpclient/CancelRequestTest.java [2024-08-10T07:54:47.237Z] TEST JDK: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image [2024-08-10T07:54:47.237Z] [2024-08-10T07:54:47.237Z] ACTION: build -- Passed. Build successful [2024-08-10T07:54:47.237Z] REASON: User specified action: run build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker CancelRequestTest [2024-08-10T07:54:47.237Z] TIME: 1.196 seconds [2024-08-10T07:54:47.237Z] messages: [2024-08-10T07:54:47.237Z] command: build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker CancelRequestTest [2024-08-10T07:54:47.237Z] reason: User specified action: run build jdk.httpclient.test.lib.common.HttpServerAdapters jdk.test.lib.net.SimpleSSLContext ReferenceTracker CancelRequestTest [2024-08-10T07:54:47.237Z] started: Sat Aug 10 07:54:22 GMT 2024 [2024-08-10T07:54:47.237Z] Test directory: [2024-08-10T07:54:47.237Z] compile: ReferenceTracker, CancelRequestTest [2024-08-10T07:54:47.237Z] finished: Sat Aug 10 07:54:23 GMT 2024 [2024-08-10T07:54:47.237Z] elapsed time (seconds): 1.196 [2024-08-10T07:54:47.237Z] [2024-08-10T07:54:47.237Z] ACTION: compile -- Passed. Compilation successful [2024-08-10T07:54:47.237Z] REASON: .class file out of date or does not exist [2024-08-10T07:54:47.237Z] TIME: 1.191 seconds [2024-08-10T07:54:47.237Z] messages: [2024-08-10T07:54:47.237Z] command: compile /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ReferenceTracker.java /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/CancelRequestTest.java [2024-08-10T07:54:47.237Z] reason: .class file out of date or does not exist [2024-08-10T07:54:47.237Z] started: Sat Aug 10 07:54:22 GMT 2024 [2024-08-10T07:54:47.237Z] 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-10T07:54:47.237Z] Mode: agentvm [2024-08-10T07:54:47.237Z] Agent id: 3 [2024-08-10T07:54:47.237Z] finished: Sat Aug 10 07:54:23 GMT 2024 [2024-08-10T07:54:47.237Z] elapsed time (seconds): 1.191 [2024-08-10T07:54:47.237Z] configuration: [2024-08-10T07:54:47.237Z] Boot Layer (javac runtime environment) [2024-08-10T07:54:47.237Z] class path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/javatest.jar [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/jtreg.jar [2024-08-10T07:54:47.237Z] patch: java.base /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/patches/java.base [2024-08-10T07:54:47.237Z] [2024-08-10T07:54:47.237Z] javac compilation environment [2024-08-10T07:54:47.237Z] add modules: java.base java.net.http java.logging jdk.httpserver [2024-08-10T07:54:47.237Z] add exports: java.base/sun.net ALL-UNNAMED [2024-08-10T07:54:47.237Z] java.base/sun.net.www ALL-UNNAMED [2024-08-10T07:54:47.237Z] java.base/sun.net.www.http ALL-UNNAMED [2024-08-10T07:54:47.237Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2024-08-10T07:54:47.237Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2024-08-10T07:54:47.237Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2024-08-10T07:54:47.237Z] source path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/lib [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib [2024-08-10T07:54:47.237Z] class path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar [2024-08-10T07:54:47.237Z] [2024-08-10T07:54:47.237Z] rerun: [2024-08-10T07:54:47.237Z] cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/scratch/2 && \ [2024-08-10T07:54:47.237Z] DISPLAY=:0 \ [2024-08-10T07:54:47.237Z] HOME=/home/jenkins \ [2024-08-10T07:54:47.237Z] PATH=/bin:/usr/bin:/usr/sbin \ [2024-08-10T07:54:47.237Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image/bin/javac \ [2024-08-10T07:54:47.237Z] -J-ea \ [2024-08-10T07:54:47.237Z] -J-esa \ [2024-08-10T07:54:47.237Z] -J-Xmx512m \ [2024-08-10T07:54:47.237Z] -J-XX:-UseCompressedOops \ [2024-08-10T07:54:47.237Z] -J-Djava.awt.headless=true \ [2024-08-10T07:54:47.237Z] -J-Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2024-08-10T07:54:47.237Z] -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2024-08-10T07:54:47.237Z] -J-Dtest.compiler.opts= \ [2024-08-10T07:54:47.237Z] -J-Dtest.java.opts= \ [2024-08-10T07:54:47.237Z] -J-Dtest.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image \ [2024-08-10T07:54:47.237Z] -J-Dcompile.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image \ [2024-08-10T07:54:47.237Z] -J-Dtest.timeout.factor=8.0 \ [2024-08-10T07:54:47.237Z] -J-Dtest.nativepath=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-10T07:54:47.237Z] -J-Dtest.root=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2024-08-10T07:54:47.237Z] -J-Dtest.name=java/net/httpclient/CancelRequestTest.java \ [2024-08-10T07:54:47.237Z] -J-Dtest.file=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/CancelRequestTest.java \ [2024-08-10T07:54:47.237Z] -J-Dtest.src=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient \ [2024-08-10T07:54:47.237Z] -J-Dtest.src.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.238Z] -J-Dtest.classes=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d \ [2024-08-10T07:54:47.238Z] -J-Dtest.class.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.238Z] -J-Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.238Z] -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-10T07:54:47.238Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2024-08-10T07:54:47.238Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2024-08-10T07:54:47.238Z] -d /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d \ [2024-08-10T07:54:47.238Z] -sourcepath /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.238Z] -classpath /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/ReferenceTracker.java /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/CancelRequestTest.java [2024-08-10T07:54:47.238Z] [2024-08-10T07:54:47.238Z] ACTION: build -- Passed. All files up to date [2024-08-10T07:54:47.238Z] REASON: Named class compiled on demand [2024-08-10T07:54:47.238Z] TIME: 0.0 seconds [2024-08-10T07:54:47.238Z] messages: [2024-08-10T07:54:47.238Z] command: build CancelRequestTest [2024-08-10T07:54:47.238Z] reason: Named class compiled on demand [2024-08-10T07:54:47.238Z] started: Sat Aug 10 07:54:23 GMT 2024 [2024-08-10T07:54:47.238Z] finished: Sat Aug 10 07:54:23 GMT 2024 [2024-08-10T07:54:47.238Z] elapsed time (seconds): 0.0 [2024-08-10T07:54:47.238Z] [2024-08-10T07:54:47.238Z] ACTION: testng -- Failed. Execution failed: `main' threw exception: java.lang.Exception: failures: 1 [2024-08-10T07:54:47.238Z] REASON: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.enableAllMethodRetry=true CancelRequestTest [2024-08-10T07:54:47.238Z] TIME: 21.921 seconds [2024-08-10T07:54:47.238Z] messages: [2024-08-10T07:54:47.238Z] command: testng -Djdk.internal.httpclient.debug=true -Djdk.httpclient.enableAllMethodRetry=true CancelRequestTest [2024-08-10T07:54:47.238Z] reason: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.enableAllMethodRetry=true CancelRequestTest [2024-08-10T07:54:47.238Z] started: Sat Aug 10 07:54:23 GMT 2024 [2024-08-10T07:54:47.238Z] Mode: othervm [/othervm specified] [2024-08-10T07:54:47.238Z] 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-10T07:54:47.238Z] finished: Sat Aug 10 07:54:45 GMT 2024 [2024-08-10T07:54:47.238Z] elapsed time (seconds): 21.921 [2024-08-10T07:54:47.238Z] configuration: [2024-08-10T07:54:47.238Z] Boot Layer [2024-08-10T07:54:47.238Z] add modules: java.base java.net.http java.logging jdk.httpserver [2024-08-10T07:54:47.238Z] add exports: java.base/sun.net ALL-UNNAMED [2024-08-10T07:54:47.238Z] java.base/sun.net.www ALL-UNNAMED [2024-08-10T07:54:47.238Z] java.base/sun.net.www.http ALL-UNNAMED [2024-08-10T07:54:47.238Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2024-08-10T07:54:47.238Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2024-08-10T07:54:47.238Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2024-08-10T07:54:47.238Z] [2024-08-10T07:54:47.238Z] STDOUT: [2024-08-10T07:54:47.238Z] Seed from RandomFactory = 4803810149082253059L [2024-08-10T07:54:47.238Z] Http1TestServer[localhost/127.0.0.1:43831]::addHandler CancelRequestTest$HTTPSlowHandler@7ed64d14, /http1/x/ [2024-08-10T07:54:47.238Z] Http1TestServer[localhost/127.0.0.1:39871]::addHandler CancelRequestTest$HTTPSlowHandler@7ed64d14, /https1/x/ [2024-08-10T07:54:47.238Z] Http2TestServerImpl[localhost/127.0.0.1:35867]::addHandler CancelRequestTest$HTTPSlowHandler@7a9afbbb, /http2/x/ [2024-08-10T07:54:47.238Z] Http2TestServerImpl[localhost/127.0.0.1:50841]::addHandler CancelRequestTest$HTTPSlowHandler@7a9afbbb, /https2/x/ [2024-08-10T07:54:47.238Z] Http1TestServer: start [2024-08-10T07:54:47.238Z] Http1TestServer: start [2024-08-10T07:54:47.238Z] Http2TestServerImpl: start [2024-08-10T07:54:47.238Z] Http2TestServerImpl: start [2024-08-10T07:54:47.238Z] config CancelRequestTest.setup(): success [2024-08-10T07:54:47.238Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.238Z] [2024-08-10T07:54:47.238Z] [1 s, 946 ms, 350588 ns] testGetSendAsync(http://127.0.0.1:43831/http1/x/new/interrupt/get, false, true) [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@60a439e7[Not completed, 1 dependents] (id=7) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@267684a4[Not completed, 1 dependents] (id=8) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@5588ee1e[Not completed] (id=9) [2024-08-10T07:54:47.238Z] client delay: 41 [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@60a439e7[Not completed, 1 dependents] (id=7) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@267684a4[Completed exceptionally: java.util.concurrent.CancellationException] (id=8) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@5588ee1e[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=9) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@35e4d40a[Not completed, 1 dependents] (id=35) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@5bfd43f7[Not completed, 1 dependents] (id=36) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@2e3e3ecb[Not completed] (id=37) [2024-08-10T07:54:47.238Z] client delay: 45 [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@35e4d40a[Not completed, 1 dependents] (id=35) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@5bfd43f7[Completed exceptionally: java.util.concurrent.CancellationException] (id=36) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@2e3e3ecb[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=37) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.net.ConnectException [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@69d0398e[Not completed, 1 dependents] (id=73) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@7a07e43a[Not completed, 1 dependents] (id=74) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@4bd4f276[Not completed] (id=75) [2024-08-10T07:54:47.238Z] client delay: 23 [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@69d0398e[Not completed, 1 dependents] (id=73) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@7a07e43a[Completed exceptionally: java.util.concurrent.CancellationException] (id=74) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@4bd4f276[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=75) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.238Z] test CancelRequestTest.testGetSendAsync("http://127.0.0.1:43831/http1/x/new/interrupt", false, true): success [2024-08-10T07:54:47.238Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.238Z] [2024-08-10T07:54:47.238Z] [2 s, 502 ms, 388970 ns] testGetSendAsync(https://127.0.0.1:39871/https1/x/new/interrupt/get, false, true) [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@40de1371[Not completed, 1 dependents] (id=112) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@3342c472[Not completed, 1 dependents] (id=113) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@5e7c1e79[Not completed] (id=114) [2024-08-10T07:54:47.238Z] client delay: 66 [2024-08-10T07:54:47.238Z] java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@40de1371[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=112) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@3342c472[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=113) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@5e7c1e79[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=114) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@44332f0f[Not completed, 1 dependents] (id=152) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@7446e963[Not completed, 1 dependents] (id=153) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@5102c2cd[Not completed] (id=154) [2024-08-10T07:54:47.238Z] client delay: 51 [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@44332f0f[Not completed, 1 dependents] (id=152) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@7446e963[Completed exceptionally: java.util.concurrent.CancellationException] (id=153) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@5102c2cd[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=154) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.238Z] response: jdk.internal.net.http.common.MinimalFuture@32a580ec[Not completed, 1 dependents] (id=191) [2024-08-10T07:54:47.238Z] cf1: jdk.internal.net.http.common.MinimalFuture@716b6a2a[Not completed, 1 dependents] (id=192) [2024-08-10T07:54:47.238Z] cf2: jdk.internal.net.http.common.MinimalFuture@36b8da60[Not completed] (id=193) [2024-08-10T07:54:47.238Z] client delay: 48 [2024-08-10T07:54:47.238Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@32a580ec[Not completed, 1 dependents] (id=191) [2024-08-10T07:54:47.238Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@716b6a2a[Completed exceptionally: java.util.concurrent.CancellationException] (id=192) [2024-08-10T07:54:47.238Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@36b8da60[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=193) [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.238Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.238Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] test CancelRequestTest.testGetSendAsync("https://127.0.0.1:39871/https1/x/new/interrupt", false, true): success [2024-08-10T07:54:47.239Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.239Z] [2024-08-10T07:54:47.239Z] [2 s, 733 ms, 29917 ns] testGetSendAsync(http://127.0.0.1:35867/http2/x/new/interrupt/get, false, true) [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@1450a2e[Not completed, 1 dependents] (id=230) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@53469fa6[Not completed, 1 dependents] (id=231) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@7dd0a386[Not completed] (id=232) [2024-08-10T07:54:47.239Z] client delay: 40 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@1450a2e[Not completed, 1 dependents] (id=230) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@53469fa6[Completed exceptionally: java.util.concurrent.CancellationException] (id=231) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@7dd0a386[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=232) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@79a712ce[Not completed, 1 dependents] (id=273) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@509a63ae[Not completed, 1 dependents] (id=274) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@37466db4[Not completed] (id=275) [2024-08-10T07:54:47.239Z] client delay: 49 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@79a712ce[Not completed, 1 dependents] (id=273) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@509a63ae[Completed exceptionally: java.util.concurrent.CancellationException] (id=274) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@37466db4[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=275) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@4f722449[Not completed, 1 dependents] (id=321) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@e827e0b[Not completed, 1 dependents] (id=322) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@d06fb66[Not completed] (id=323) [2024-08-10T07:54:47.239Z] client delay: 55 [2024-08-10T07:54:47.239Z] java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@4f722449[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=321) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@e827e0b[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=322) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@d06fb66[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=323) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] test CancelRequestTest.testGetSendAsync("http://127.0.0.1:35867/http2/x/new/interrupt", false, true): success [2024-08-10T07:54:47.239Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.239Z] [2024-08-10T07:54:47.239Z] [3 s, 81 ms, 942649 ns] testGetSendAsync(https://127.0.0.1:50841/https2/x/new/interrupt/get, false, true) [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@312246cc[Not completed, 1 dependents] (id=384) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@5f66b30e[Not completed, 1 dependents] (id=385) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@565cc4cb[Not completed] (id=386) [2024-08-10T07:54:47.239Z] client delay: 15 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@312246cc[Not completed, 1 dependents] (id=384) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@5f66b30e[Completed exceptionally: java.util.concurrent.CancellationException] (id=385) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@565cc4cb[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=386) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: javax.net.ssl.SSLHandshakeException: Remote host terminated the handshake [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@1d7b2c9a[Not completed, 1 dependents] (id=427) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@3e729196[Not completed, 1 dependents] (id=428) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@56b4be7d[Not completed] (id=429) [2024-08-10T07:54:47.239Z] client delay: 43 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@1d7b2c9a[Not completed, 1 dependents] (id=427) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@3e729196[Completed exceptionally: java.util.concurrent.CancellationException] (id=428) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@56b4be7d[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=429) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@37f6500c[Not completed, 1 dependents] (id=466) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@444247d9[Not completed, 1 dependents] (id=467) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@568bd0d3[Not completed] (id=468) [2024-08-10T07:54:47.239Z] client delay: 7 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@37f6500c[Not completed, 1 dependents] (id=466) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@444247d9[Completed exceptionally: java.util.concurrent.CancellationException] (id=467) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@568bd0d3[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=468) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] test CancelRequestTest.testGetSendAsync("https://127.0.0.1:50841/https2/x/new/interrupt", false, true): success [2024-08-10T07:54:47.239Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.239Z] [2024-08-10T07:54:47.239Z] [3 s, 232 ms, 698267 ns] testGetSendAsync(http://127.0.0.1:43831/http1/x/same/interrupt/get, true, true) [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@c9949bd[Not completed, 1 dependents] (id=503) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@49c0db5[Not completed, 1 dependents] (id=504) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@5c670aeb[Not completed] (id=505) [2024-08-10T07:54:47.239Z] client delay: 61 [2024-08-10T07:54:47.239Z] HTTPSlowHandler received request to /http1/x/same/interrupt/get [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@c9949bd[Not completed, 1 dependents] (id=503) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@49c0db5[Completed exceptionally: java.util.concurrent.CancellationException] (id=504) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@5c670aeb[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=505) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@3919cfcd[Not completed, 1 dependents] (id=554) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@5d4daa57[Not completed, 1 dependents] (id=555) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@310fe113[Not completed] (id=556) [2024-08-10T07:54:47.239Z] client delay: 33 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@3919cfcd[Not completed, 1 dependents] (id=554) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@5d4daa57[Completed exceptionally: java.util.concurrent.CancellationException] (id=555) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@310fe113[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=556) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@4f064bf3[Not completed, 1 dependents] (id=605) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@1cf2c79[Not completed, 1 dependents] (id=606) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@4573bc86[Not completed] (id=607) [2024-08-10T07:54:47.239Z] client delay: 30 [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@4f064bf3[Not completed, 1 dependents] (id=605) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@1cf2c79[Completed exceptionally: java.util.concurrent.CancellationException] (id=606) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@4573bc86[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException] (id=607) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.239Z] test CancelRequestTest.testGetSendAsync("http://127.0.0.1:43831/http1/x/same/interrupt", true, true): success [2024-08-10T07:54:47.239Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.239Z] [2024-08-10T07:54:47.239Z] [3 s, 382 ms, 4780 ns] testGetSendAsync(https://127.0.0.1:39871/https1/x/same/interrupt/get, true, true) [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@15ba6055[Not completed, 1 dependents] (id=683) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@4641b9a8[Not completed, 1 dependents] (id=684) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@4e3f17d2[Not completed] (id=685) [2024-08-10T07:54:47.239Z] client delay: 48 [2024-08-10T07:54:47.239Z] java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@15ba6055[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=683) [2024-08-10T07:54:47.239Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@4641b9a8[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=684) [2024-08-10T07:54:47.239Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@4e3f17d2[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=685) [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.239Z] cause: javax.net.ssl.SSLHandshakeException: Remote host terminated the handshake [2024-08-10T07:54:47.239Z] response: jdk.internal.net.http.common.MinimalFuture@78973847[Not completed, 1 dependents] (id=699) [2024-08-10T07:54:47.239Z] cf1: jdk.internal.net.http.common.MinimalFuture@72527a12[Not completed, 1 dependents] (id=700) [2024-08-10T07:54:47.239Z] cf2: jdk.internal.net.http.common.MinimalFuture@4d9b9879[Not completed] (id=701) [2024-08-10T07:54:47.239Z] client delay: 38 [2024-08-10T07:54:47.239Z] HTTPSlowHandler: unexpected exception: java.io.IOException: Broken pipe [2024-08-10T07:54:47.239Z] HTTPSlowHandler reply sent: /http1/x/same/interrupt/get [2024-08-10T07:54:47.239Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: Broken pipe [2024-08-10T07:54:47.239Z] java.io.IOException: Broken pipe [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.239Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.write(Request.java:393) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.flush(ExchangeImpl.java:469) [2024-08-10T07:54:47.239Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:630) [2024-08-10T07:54:47.239Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.239Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttpHandler$0(HttpServerAdapters.java:387) [2024-08-10T07:54:47.239Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82) [2024-08-10T07:54:47.239Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:98) [2024-08-10T07:54:47.239Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:851) [2024-08-10T07:54:47.239Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:818) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:201) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:561) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:526) [2024-08-10T07:54:47.240Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.240Z] Suppressed: java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.write(Request.java:393) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.close(ChunkedOutputStream.java:134) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.close(ExchangeImpl.java:474) [2024-08-10T07:54:47.240Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:621) [2024-08-10T07:54:47.240Z] ... 12 more [2024-08-10T07:54:47.240Z] HTTPSlowHandler received request to /http1/x/same/interrupt/get [2024-08-10T07:54:47.240Z] HTTPSlowHandler: unexpected exception: java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] HTTPSlowHandler reply sent: /http1/x/same/interrupt/get [2024-08-10T07:54:47.240Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.write(Request.java:393) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.flush(ExchangeImpl.java:469) [2024-08-10T07:54:47.240Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:630) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttpHandler$0(HttpServerAdapters.java:387) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:98) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:851) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:818) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:201) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:561) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:526) [2024-08-10T07:54:47.240Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.240Z] Suppressed: java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.write(Request.java:393) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.close(ChunkedOutputStream.java:134) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.close(ExchangeImpl.java:474) [2024-08-10T07:54:47.240Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:621) [2024-08-10T07:54:47.240Z] ... 12 more [2024-08-10T07:54:47.240Z] HTTPSlowHandler received request to /http1/x/same/interrupt/get [2024-08-10T07:54:47.240Z] java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@78973847[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=699) [2024-08-10T07:54:47.240Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@72527a12[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=700) [2024-08-10T07:54:47.240Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@4d9b9879[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=701) [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] CancellationException cause: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] cause: javax.net.ssl.SSLHandshakeException: Remote host terminated the handshake [2024-08-10T07:54:47.240Z] response: jdk.internal.net.http.common.MinimalFuture@33f43168[Not completed, 1 dependents] (id=742) [2024-08-10T07:54:47.240Z] cf1: jdk.internal.net.http.common.MinimalFuture@61a869cd[Not completed, 1 dependents] (id=743) [2024-08-10T07:54:47.240Z] cf2: jdk.internal.net.http.common.MinimalFuture@50aba208[Not completed] (id=744) [2024-08-10T07:54:47.240Z] client delay: 73 [2024-08-10T07:54:47.240Z] HTTPSlowHandler: unexpected exception: java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] HTTPSlowHandler reply sent: /http1/x/same/interrupt/get [2024-08-10T07:54:47.240Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.write(Request.java:393) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.flush(ExchangeImpl.java:469) [2024-08-10T07:54:47.240Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:630) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttpHandler$0(HttpServerAdapters.java:387) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:98) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:851) [2024-08-10T07:54:47.240Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:818) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:201) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:561) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:526) [2024-08-10T07:54:47.240Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.240Z] Suppressed: java.io.IOException: Broken pipe [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.240Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.240Z] at jdk.httpserver/sun.net.httpserver.Request$WriteStream.wri [2024-08-10T07:54:47.240Z] [2024-08-10T07:54:47.240Z] ... [2024-08-10T07:54:47.240Z] Output overflow: [2024-08-10T07:54:47.240Z] JT Harness has limited the test output to the text [2024-08-10T07:54:47.240Z] at the beginning and the end, so that you can see how the [2024-08-10T07:54:47.240Z] test began, and how it completed. [2024-08-10T07:54:47.240Z] [2024-08-10T07:54:47.240Z] If you need to see more of the output from the test, [2024-08-10T07:54:47.240Z] set the system property javatest.maxOutputSize to a higher [2024-08-10T07:54:47.240Z] value. The current value is 100000 [2024-08-10T07:54:47.240Z] ... [2024-08-10T07:54:47.240Z] [2024-08-10T07:54:47.240Z] tpServerAdapters.java:932) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.240Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.240Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: closed [2024-08-10T07:54:47.240Z] java.io.IOException: closed [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.write(BodyOutputStream.java:84) [2024-08-10T07:54:47.240Z] at java.base/java.io.OutputStream.write(OutputStream.java:127) [2024-08-10T07:54:47.240Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:629) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.240Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.240Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.240Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.240Z] Server wrote 12 bytes [2024-08-10T07:54:47.240Z] waiting for completion on: java.util.concurrent.CompletableFuture@285b2f91[Completed normally] [2024-08-10T07:54:47.240Z] Cancelling from Thread[pool-1-thread-3,5,MainThreadGroup] [2024-08-10T07:54:47.240Z] cancelled jdk.internal.net.http.common.MinimalFuture@21cd6f8c[Completed exceptionally: java.util.concurrent.CancellationException] (id=5563) [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.240Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.240Z] cause: java.io.IOException: Stream 1 cancelled [2024-08-10T07:54:47.240Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/new/interrupt", false, true): success [2024-08-10T07:54:47.240Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.240Z] [2024-08-10T07:54:47.240Z] [17 s, 312 ms, 340253 ns] testPostSendAsync(http://127.0.0.1:43831/http1/x/same/interrupt/post, true, true) [2024-08-10T07:54:47.240Z] response: jdk.internal.net.http.common.MinimalFuture@6e11de17[Not completed, 1 dependents] (id=5619) [2024-08-10T07:54:47.240Z] cf1: jdk.internal.net.http.common.MinimalFuture@2609db72[Not completed, 1 dependents] (id=5620) [2024-08-10T07:54:47.240Z] cf2: jdk.internal.net.http.common.MinimalFuture@eb6265e[Not completed] (id=5621) [2024-08-10T07:54:47.240Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@6e11de17[Not completed, 1 dependents] (id=5619) [2024-08-10T07:54:47.240Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@2609db72[Not completed, 1 dependents] (id=5620) [2024-08-10T07:54:47.240Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@eb6265e[Not completed] (id=5621) [2024-08-10T07:54:47.240Z] waiting for completion on: java.util.concurrent.CompletableFuture@a0b6007[Completed normally] [2024-08-10T07:54:47.242Z] Cancelling from Thread[pool-1-thread-2,5,MainThreadGroup] [2024-08-10T07:54:47.242Z] cancelled jdk.internal.net.http.common.MinimalFuture@2609db72[Completed exceptionally: java.util.concurrent.CancellationException] (id=5620) [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.242Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.242Z] response: jdk.internal.net.http.common.MinimalFuture@790bd1ad[Not completed, 1 dependents] (id=5670) [2024-08-10T07:54:47.242Z] cf1: jdk.internal.net.http.common.MinimalFuture@190a49fd[Not completed, 1 dependents] (id=5671) [2024-08-10T07:54:47.242Z] cf2: jdk.internal.net.http.common.MinimalFuture@7130d3e5[Not completed] (id=5672) [2024-08-10T07:54:47.242Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@790bd1ad[Not completed, 1 dependents] (id=5670) [2024-08-10T07:54:47.242Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@190a49fd[Not completed, 1 dependents] (id=5671) [2024-08-10T07:54:47.242Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@7130d3e5[Not completed] (id=5672) [2024-08-10T07:54:47.242Z] waiting for completion on: java.util.concurrent.CompletableFuture@5df57ace[Completed normally] [2024-08-10T07:54:47.242Z] Cancelling from Thread[pool-1-thread-4,5,MainThreadGroup] [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] cancelled jdk.internal.net.http.common.MinimalFuture@190a49fd[Completed exceptionally: java.util.concurrent.CancellationException] (id=5671) [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.242Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.242Z] response: jdk.internal.net.http.common.MinimalFuture@4e8b9f4b[Not completed, 1 dependents] (id=5721) [2024-08-10T07:54:47.242Z] cf1: jdk.internal.net.http.common.MinimalFuture@69aab98e[Not completed, 1 dependents] (id=5722) [2024-08-10T07:54:47.242Z] cf2: jdk.internal.net.http.common.MinimalFuture@22a450e7[Not completed] (id=5723) [2024-08-10T07:54:47.242Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@4e8b9f4b[Not completed, 1 dependents] (id=5721) [2024-08-10T07:54:47.242Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@69aab98e[Not completed, 1 dependents] (id=5722) [2024-08-10T07:54:47.242Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@22a450e7[Not completed] (id=5723) [2024-08-10T07:54:47.242Z] waiting for completion on: java.util.concurrent.CompletableFuture@6eae52ff[Completed normally] [2024-08-10T07:54:47.242Z] HTTPSlowHandler received request to /http1/x/same/interrupt/post [2024-08-10T07:54:47.242Z] Cancelling from Thread[pool-1-thread-2,5,MainThreadGroup] [2024-08-10T07:54:47.242Z] cancelled jdk.internal.net.http.common.MinimalFuture@69aab98e[Completed exceptionally: java.util.concurrent.CancellationException] (id=5722) [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.242Z] HTTPSlowHandler: unexpected exception: java.io.IOException: end of stream reading chunk header [2024-08-10T07:54:47.242Z] HTTPSlowHandler reply sent: /http1/x/same/interrupt/post [2024-08-10T07:54:47.242Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: end of stream reading chunk header [2024-08-10T07:54:47.242Z] java.io.IOException: end of stream reading chunk header [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ChunkedInputStream.readChunkHeader(ChunkedInputStream.java:110) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ChunkedInputStream.readImpl(ChunkedInputStream.java:118) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.LeftOverInputStream.read(LeftOverInputStream.java:99) [2024-08-10T07:54:47.242Z] at java.base/java.io.InputStream.readNBytes(InputStream.java:409) [2024-08-10T07:54:47.242Z] at java.base/java.io.InputStream.readAllBytes(InputStream.java:346) [2024-08-10T07:54:47.242Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:618) [2024-08-10T07:54:47.242Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.242Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttpHandler$0(HttpServerAdapters.java:387) [2024-08-10T07:54:47.242Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82) [2024-08-10T07:54:47.242Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:98) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:851) [2024-08-10T07:54:47.242Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:818) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:201) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:561) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:526) [2024-08-10T07:54:47.242Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.242Z] Suppressed: java.io.IOException: end of stream reading chunk header [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ChunkedInputStream.readChunkHeader(ChunkedInputStream.java:110) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.ChunkedInputStream.readImpl(ChunkedInputStream.java:118) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.LeftOverInputStream.drain(LeftOverInputStream.java:115) [2024-08-10T07:54:47.242Z] at jdk.httpserver/sun.net.httpserver.LeftOverInputStream.close(LeftOverInputStream.java:69) [2024-08-10T07:54:47.242Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:617) [2024-08-10T07:54:47.243Z] ... 12 more [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.243Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:43831/http1/x/same/interrupt", true, true): success [2024-08-10T07:54:47.243Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.243Z] [2024-08-10T07:54:47.243Z] [17 s, 358 ms, 811343 ns] testPostSendAsync(https://127.0.0.1:39871/https1/x/same/interrupt/post, true, true) [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@7bc50b3a[Not completed, 1 dependents] (id=5772) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@7be65fcd[Not completed, 1 dependents] (id=5773) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@4e2a5174[Not completed] (id=5774) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@7bc50b3a[Not completed, 1 dependents] (id=5772) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@7be65fcd[Not completed, 1 dependents] (id=5773) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@4e2a5174[Not completed] (id=5774) [2024-08-10T07:54:47.243Z] Server wrote 20 bytes [2024-08-10T07:54:47.243Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@10cbf192 [2024-08-10T07:54:47.243Z] HTTPSlowHandler received request to https://127.0.0.1:50841/https2/x/new/interrupt/post [2024-08-10T07:54:47.243Z] Server wrote 6 bytes [2024-08-10T07:54:47.243Z] HTTPSlowHandler reply sent: https://127.0.0.1:50841/https2/x/new/interrupt/post [2024-08-10T07:54:47.243Z] Server wrote 12 bytes [2024-08-10T07:54:47.243Z] Server wrote 12 bytes [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@6ef1a38b[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-4,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@7be65fcd[Completed exceptionally: java.util.concurrent.CancellationException] (id=5773) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@746beff3[Not completed, 1 dependents] (id=5832) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@2724a69f[Not completed, 1 dependents] (id=5833) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@6ef59d81[Not completed] (id=5834) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@746beff3[Not completed, 1 dependents] (id=5832) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@2724a69f[Not completed, 1 dependents] (id=5833) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@6ef59d81[Not completed] (id=5834) [2024-08-10T07:54:47.243Z] Server wrote 20 bytes [2024-08-10T07:54:47.243Z] Server wrote 6 bytes [2024-08-10T07:54:47.243Z] HTTPSlowHandler reply sent: https://127.0.0.1:50841/https2/x/new/interrupt/post [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@3e64855[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-3,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] HTTPSlowHandler received request to /https1/x/same/interrupt/post [2024-08-10T07:54:47.243Z] java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@2724a69f[Completed exceptionally: java.util.concurrent.CompletionException: java.util.concurrent.CancellationException: Request cancelled] (id=5833) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@7248c0da[Not completed, 1 dependents] (id=5895) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@5977ad17[Not completed, 1 dependents] (id=5896) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@5be5e8f8[Not completed] (id=5897) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@7248c0da[Not completed, 1 dependents] (id=5895) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@5977ad17[Not completed, 1 dependents] (id=5896) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@5be5e8f8[Not completed] (id=5897) [2024-08-10T07:54:47.243Z] Server wrote 12 bytes [2024-08-10T07:54:47.243Z] HTTPSlowHandler: unexpected exception: java.io.IOException: Broken pipe [2024-08-10T07:54:47.243Z] HTTPSlowHandler reply sent: /https1/x/same/interrupt/post [2024-08-10T07:54:47.243Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: Broken pipe [2024-08-10T07:54:47.243Z] java.io.IOException: Broken pipe [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$EngineWrapper.wrapAndSendX(SSLStreams.java:296) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$EngineWrapper.wrapAndSend(SSLStreams.java:269) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams.sendData(SSLStreams.java:377) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$OutputStream.write(SSLStreams.java:639) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.flush(ExchangeImpl.java:469) [2024-08-10T07:54:47.243Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:630) [2024-08-10T07:54:47.243Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.243Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttpHandler$0(HttpServerAdapters.java:387) [2024-08-10T07:54:47.243Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82) [2024-08-10T07:54:47.243Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:98) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:851) [2024-08-10T07:54:47.243Z] at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:95) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:816) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:201) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:561) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:526) [2024-08-10T07:54:47.243Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.243Z] Suppressed: java.io.IOException: Broken pipe [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.FileDispatcherImpl.write0(Native Method) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:132) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:97) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:53) [2024-08-10T07:54:47.243Z] at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:532) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$EngineWrapper.wrapAndSendX(SSLStreams.java:296) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$EngineWrapper.wrapAndSend(SSLStreams.java:269) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams.sendData(SSLStreams.java:377) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.SSLStreams$OutputStream.write(SSLStreams.java:639) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.ChunkedOutputStream.close(ChunkedOutputStream.java:134) [2024-08-10T07:54:47.243Z] at jdk.httpserver/sun.net.httpserver.PlaceholderOutputStream.close(ExchangeImpl.java:474) [2024-08-10T07:54:47.243Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:621) [2024-08-10T07:54:47.243Z] ... 12 more [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@5c021771[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-4,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@5977ad17[Completed exceptionally: java.util.concurrent.CancellationException] (id=5896) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Request cancelled [2024-08-10T07:54:47.243Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:39871/https1/x/same/interrupt", true, true): success [2024-08-10T07:54:47.243Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.243Z] [2024-08-10T07:54:47.243Z] [18 s, 37 ms, 952225 ns] testPostSendAsync(http://127.0.0.1:35867/http2/x/same/interrupt/post, true, true) [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@49bf2dd7[Not completed, 1 dependents] (id=5955) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@3de9be30[Not completed, 1 dependents] (id=5956) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@57c184e2[Not completed] (id=5957) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@49bf2dd7[Not completed, 1 dependents] (id=5955) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@3de9be30[Not completed, 1 dependents] (id=5956) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@57c184e2[Not completed] (id=5957) [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@3593e605[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-3,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@3de9be30[Completed exceptionally: java.util.concurrent.CancellationException] (id=5956) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Stream 23 cancelled [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@5b9a03ad[Not completed, 1 dependents] (id=5988) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@6b7b5c9c[Not completed, 1 dependents] (id=5989) [2024-08-10T07:54:47.243Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@41620e83 [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@1b1367fd[Not completed] (id=5990) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@5b9a03ad[Not completed, 1 dependents] (id=5988) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@6b7b5c9c[Not completed, 1 dependents] (id=5989) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@1b1367fd[Not completed] (id=5990) [2024-08-10T07:54:47.243Z] HTTPSlowHandler received request to http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@1562facf[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-2,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@6b7b5c9c[Completed exceptionally: java.util.concurrent.CancellationException] (id=5989) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@34089c12 [2024-08-10T07:54:47.243Z] HTTPSlowHandler received request to http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Stream 25 cancelled [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@402e06e9[Not completed, 1 dependents] (id=6021) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@4ba2e22a[Not completed, 1 dependents] (id=6022) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@7a0cc87e[Not completed] (id=6023) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@402e06e9[Not completed, 1 dependents] (id=6021) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@4ba2e22a[Not completed, 1 dependents] (id=6022) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@7a0cc87e[Not completed] (id=6023) [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@565a988f[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-2,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@4ba2e22a[Completed exceptionally: java.util.concurrent.CancellationException] (id=6022) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Stream 27 cancelled [2024-08-10T07:54:47.243Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:35867/http2/x/same/interrupt", true, true): success [2024-08-10T07:54:47.243Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.243Z] [2024-08-10T07:54:47.243Z] [18 s, 61 ms, 591922 ns] testPostSendAsync(https://127.0.0.1:50841/https2/x/same/interrupt/post, true, true) [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@16e63477[Not completed, 1 dependents] (id=6054) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@ab541ed[Not completed, 1 dependents] (id=6055) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@73ce4efa[Not completed] (id=6056) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@16e63477[Not completed, 1 dependents] (id=6054) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@ab541ed[Not completed, 1 dependents] (id=6055) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@73ce4efa[Not completed] (id=6056) [2024-08-10T07:54:47.243Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@3be761c3 [2024-08-10T07:54:47.243Z] HTTPSlowHandler received request to https://127.0.0.1:50841/https2/x/same/interrupt/post [2024-08-10T07:54:47.243Z] waiting for completion on: java.util.concurrent.CompletableFuture@7330bf41[Completed normally] [2024-08-10T07:54:47.243Z] Cancelling from Thread[pool-1-thread-2,5,MainThreadGroup] [2024-08-10T07:54:47.243Z] cancelled jdk.internal.net.http.common.MinimalFuture@ab541ed[Completed exceptionally: java.util.concurrent.CancellationException] (id=6055) [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.243Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.243Z] cause: java.io.IOException: Stream 19 cancelled [2024-08-10T07:54:47.243Z] response: jdk.internal.net.http.common.MinimalFuture@7021e061[Not completed, 1 dependents] (id=6087) [2024-08-10T07:54:47.243Z] cf1: jdk.internal.net.http.common.MinimalFuture@5743279e[Not completed, 1 dependents] (id=6088) [2024-08-10T07:54:47.243Z] cf2: jdk.internal.net.http.common.MinimalFuture@7759beb2[Not completed] (id=6089) [2024-08-10T07:54:47.243Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@7021e061[Not completed, 1 dependents] (id=6087) [2024-08-10T07:54:47.243Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@5743279e[Not completed, 1 dependents] (id=6088) [2024-08-10T07:54:47.243Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@7759beb2[Not completed] (id=6089) [2024-08-10T07:54:47.244Z] waiting for completion on: java.util.concurrent.CompletableFuture@7bf9a79d[Completed normally] [2024-08-10T07:54:47.244Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@554fd99b [2024-08-10T07:54:47.244Z] HTTPSlowHandler received request to http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.244Z] Cancelling from Thread[pool-1-thread-3,5,MainThreadGroup] [2024-08-10T07:54:47.244Z] cancelled jdk.internal.net.http.common.MinimalFuture@5743279e[Completed exceptionally: java.util.concurrent.CancellationException] (id=6088) [2024-08-10T07:54:47.244Z] Got expected exception: java.util.concurrent.ExecutionException: java.util.concurrent.CancellationException [2024-08-10T07:54:47.244Z] Got expected exception: java.util.concurrent.CancellationException [2024-08-10T07:54:47.244Z] Got expected exception: java.util.concurrent.CancellationException: Request cancelled [2024-08-10T07:54:47.244Z] cause: java.io.IOException: Stream 21 cancelled [2024-08-10T07:54:47.244Z] response: jdk.internal.net.http.common.MinimalFuture@76e1873d[Not completed, 1 dependents] (id=6120) [2024-08-10T07:54:47.244Z] cf1: jdk.internal.net.http.common.MinimalFuture@9bc5368[Not completed, 1 dependents] (id=6121) [2024-08-10T07:54:47.244Z] cf2: jdk.internal.net.http.common.MinimalFuture@478dea16[Not completed] (id=6122) [2024-08-10T07:54:47.244Z] response after cancel: jdk.internal.net.http.common.MinimalFuture@76e1873d[Not completed, 1 dependents] (id=6120) [2024-08-10T07:54:47.244Z] cf1 after cancel: jdk.internal.net.http.common.MinimalFuture@9bc5368[Not completed, 1 dependents] (id=6121) [2024-08-10T07:54:47.244Z] cf2 after cancel: jdk.internal.net.http.common.MinimalFuture@478dea16[Not completed] (id=6122) [2024-08-10T07:54:47.244Z] waiting for completion on: java.util.concurrent.CompletableFuture@4f181f02[Completed normally] [2024-08-10T07:54:47.244Z] java.util.concurrent.CompletionException: java.io.IOException: Broken pipe [2024-08-10T07:54:47.244Z] Got expected exception: java.util.concurrent.ExecutionException: java.io.IOException: Broken pipe [2024-08-10T07:54:47.244Z] Cancelling from Thread[pool-1-thread-3,5,MainThreadGroup] [2024-08-10T07:54:47.244Z] cancelled jdk.internal.net.http.common.MinimalFuture@9bc5368[Completed exceptionally: java.util.concurrent.CompletionException: java.io.IOException: Broken pipe] (id=6121) [2024-08-10T07:54:47.244Z] Http2TestContext::handle Http2TestExchangeImpl: jdk.httpclient.test.lib.http2.Http2TestExchangeImpl@9091ea2 [2024-08-10T07:54:47.244Z] HTTPSlowHandler received request to https://127.0.0.1:50841/https2/x/same/interrupt/post [2024-08-10T07:54:47.244Z] HTTPSlowHandler: unexpected exception: java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] HTTPSlowHandler reply sent: https://127.0.0.1:50841/https2/x/same/interrupt/post [2024-08-10T07:54:47.244Z] WARNING: exception caught in Http2Chain::doFilter java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.sendWindowUpdates(Http2TestServerConnection.java:506) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.getData(BodyInputStream.java:77) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.getBuffer(BodyInputStream.java:85) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.read(BodyInputStream.java:108) [2024-08-10T07:54:47.244Z] at java.base/java.io.InputStream.readNBytes(InputStream.java:409) [2024-08-10T07:54:47.244Z] at java.base/java.io.InputStream.readAllBytes(InputStream.java:346) [2024-08-10T07:54:47.244Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:618) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.244Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.244Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.sendWindowUpdates(Http2TestServerConnection.java:506) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.getData(BodyInputStream.java:77) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.getBuffer(BodyInputStream.java:85) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.BodyInputStream.read(BodyInputStream.java:108) [2024-08-10T07:54:47.244Z] at java.base/java.io.InputStream.readNBytes(InputStream.java:409) [2024-08-10T07:54:47.244Z] at java.base/java.io.InputStream.readAllBytes(InputStream.java:346) [2024-08-10T07:54:47.244Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:618) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.244Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.244Z] HTTPSlowHandler: unexpected exception: java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] HTTPSlowHandler reply sent: https://127.0.0.1:50841/https2/x/same/interrupt/post [2024-08-10T07:54:47.244Z] WARNING: exception caught in Http2Chain::doFilter java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestExchangeImpl.sendResponseHeaders(Http2TestExchangeImpl.java:153) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestExchange$Http2TestExchangeImpl.sendResponseHeaders(HttpServerAdapters.java:346) [2024-08-10T07:54:47.244Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:620) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.244Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.244Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] java.io.IOException: stream closed [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestExchangeImpl.sendResponseHeaders(Http2TestExchangeImpl.java:153) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestExchange$Http2TestExchangeImpl.sendResponseHeaders(HttpServerAdapters.java:346) [2024-08-10T07:54:47.244Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:620) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.244Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.244Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.244Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/same/interrupt", true, true): failure [2024-08-10T07:54:47.244Z] java.lang.AssertionError: expected [true] but found [false] [2024-08-10T07:54:47.244Z] at org.testng.Assert.fail(Assert.java:99) [2024-08-10T07:54:47.244Z] at org.testng.Assert.failNotEquals(Assert.java:1037) [2024-08-10T07:54:47.244Z] at org.testng.Assert.assertTrue(Assert.java:45) [2024-08-10T07:54:47.244Z] at org.testng.Assert.assertTrue(Assert.java:55) [2024-08-10T07:54:47.244Z] at CancelRequestTest.testPostSendAsync(CancelRequestTest.java:435) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2024-08-10T07:54:47.244Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2024-08-10T07:54:47.244Z] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) [2024-08-10T07:54:47.244Z] at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) [2024-08-10T07:54:47.244Z] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) [2024-08-10T07:54:47.244Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2024-08-10T07:54:47.244Z] at org.testng.TestRunner.privateRun(TestRunner.java:764) [2024-08-10T07:54:47.244Z] at org.testng.TestRunner.run(TestRunner.java:585) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunner.run(SuiteRunner.java:286) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) [2024-08-10T07:54:47.244Z] at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) [2024-08-10T07:54:47.244Z] at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) [2024-08-10T07:54:47.244Z] at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) [2024-08-10T07:54:47.244Z] at org.testng.TestNG.runSuites(TestNG.java:1069) [2024-08-10T07:54:47.244Z] at org.testng.TestNG.run(TestNG.java:1037) [2024-08-10T07:54:47.244Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) [2024-08-10T07:54:47.244Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2024-08-10T07:54:47.244Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2024-08-10T07:54:47.244Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2024-08-10T07:54:47.244Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2024-08-10T07:54:47.244Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:43831/http1/x/new/nointerrupt", false, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:39871/https1/x/new/nointerrupt", false, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:35867/http2/x/new/nointerrupt", false, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/new/nointerrupt", false, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:43831/http1/x/same/nointerrupt", true, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:39871/https1/x/same/nointerrupt", true, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] Server wrote 12 bytes [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:35867/http2/x/same/nointerrupt", true, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/same/nointerrupt", true, false): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:43831/http1/x/new/interrupt", false, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:39871/https1/x/new/interrupt", false, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:35867/http2/x/new/interrupt", false, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/new/interrupt", false, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:43831/http1/x/same/interrupt", true, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] Server wrote 12 bytes [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:39871/https1/x/same/interrupt", true, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("http://127.0.0.1:35867/http2/x/same/interrupt", true, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] config CancelRequestTest.beforeMethod(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.244Z] test CancelRequestTest.testPostSendAsync("https://127.0.0.1:50841/https2/x/same/interrupt", true, true): skip [2024-08-10T07:54:47.244Z] org.testng.SkipException: some tests failed [2024-08-10T07:54:47.244Z] [2024-08-10T07:54:47.244Z] ========================= [2024-08-10T07:54:47.244Z] [2024-08-10T07:54:47.244Z] [18 s, 165 ms, 108346 ns] Created 4 servers and 61 clients [2024-08-10T07:54:47.244Z] Failed tests: [2024-08-10T07:54:47.244Z] testPostSendAsync[https://127.0.0.1:50841/https2/x/same/interrupt, true, true]: java.lang.AssertionError: expected [true] but found [false] [2024-08-10T07:54:47.244Z] java.lang.AssertionError: expected [true] but found [false] [2024-08-10T07:54:47.244Z] at org.testng.Assert.fail(Assert.java:99) [2024-08-10T07:54:47.244Z] at org.testng.Assert.failNotEquals(Assert.java:1037) [2024-08-10T07:54:47.245Z] at org.testng.Assert.assertTrue(Assert.java:45) [2024-08-10T07:54:47.245Z] at org.testng.Assert.assertTrue(Assert.java:55) [2024-08-10T07:54:47.245Z] at CancelRequestTest.testPostSendAsync(CancelRequestTest.java:435) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2024-08-10T07:54:47.245Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2024-08-10T07:54:47.245Z] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) [2024-08-10T07:54:47.245Z] at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) [2024-08-10T07:54:47.245Z] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) [2024-08-10T07:54:47.245Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2024-08-10T07:54:47.245Z] at org.testng.TestRunner.privateRun(TestRunner.java:764) [2024-08-10T07:54:47.245Z] at org.testng.TestRunner.run(TestRunner.java:585) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunner.run(SuiteRunner.java:286) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) [2024-08-10T07:54:47.245Z] at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) [2024-08-10T07:54:47.245Z] at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) [2024-08-10T07:54:47.245Z] at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) [2024-08-10T07:54:47.245Z] at org.testng.TestNG.runSuites(TestNG.java:1069) [2024-08-10T07:54:47.245Z] at org.testng.TestNG.run(TestNG.java:1037) [2024-08-10T07:54:47.245Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) [2024-08-10T07:54:47.245Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2024-08-10T07:54:47.245Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2024-08-10T07:54:47.245Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2024-08-10T07:54:47.245Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2024-08-10T07:54:47.245Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.245Z] [2024-08-10T07:54:47.245Z] ========================= [2024-08-10T07:54:47.245Z] [2024-08-10T07:54:47.245Z] config CancelRequestTest.printFailedTests(org.testng.TestRunner@3b28bd47): success [2024-08-10T07:54:47.245Z] Server wrote 12 bytes [2024-08-10T07:54:47.245Z] Server wrote 12 bytes [2024-08-10T07:54:47.245Z] Server wrote 12 bytes [2024-08-10T07:54:47.245Z] Server wrote 12 bytes [2024-08-10T07:54:47.245Z] Server wrote 20 bytes [2024-08-10T07:54:47.245Z] PASSED: No outstanding operations found in 61 clients [2024-08-10T07:54:47.245Z] Http1TestServer: stop [2024-08-10T07:54:47.245Z] Http1TestServer: stop [2024-08-10T07:54:47.245Z] Http2TestServerImpl: stop [2024-08-10T07:54:47.245Z] Http2TestServerImpl: stop [2024-08-10T07:54:47.245Z] Server wrote 6 bytes [2024-08-10T07:54:47.245Z] HTTPSlowHandler reply sent: http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.245Z] Server wrote 20 bytes [2024-08-10T07:54:47.245Z] HTTPSlowHandler: unexpected exception: java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] HTTPSlowHandler reply sent: http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.245Z] WARNING: exception caught in Http2Chain::doFilter java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.send(BodyOutputStream.java:110) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.write(BodyOutputStream.java:95) [2024-08-10T07:54:47.245Z] at java.base/java.io.OutputStream.write(OutputStream.java:127) [2024-08-10T07:54:47.245Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:629) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.245Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.245Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.send(BodyOutputStream.java:110) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.write(BodyOutputStream.java:95) [2024-08-10T07:54:47.245Z] at java.base/java.io.OutputStream.write(OutputStream.java:127) [2024-08-10T07:54:47.245Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:629) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.245Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.245Z] Server wrote 20 bytes [2024-08-10T07:54:47.245Z] HTTPSlowHandler: unexpected exception: java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] HTTPSlowHandler reply sent: http://127.0.0.1:35867/http2/x/same/interrupt/post [2024-08-10T07:54:47.245Z] WARNING: exception caught in Http2Chain::doFilter java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.send(BodyOutputStream.java:110) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.write(BodyOutputStream.java:95) [2024-08-10T07:54:47.245Z] at java.base/java.io.OutputStream.write(OutputStream.java:127) [2024-08-10T07:54:47.245Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:629) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.245Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.245Z] WARNING: exception caught in HttpTestHandler::handle java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] java.io.IOException: stream closed [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Queue.put(Queue.java:64) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.send(BodyOutputStream.java:110) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.BodyOutputStream.write(BodyOutputStream.java:95) [2024-08-10T07:54:47.245Z] at java.base/java.io.OutputStream.write(OutputStream.java:127) [2024-08-10T07:54:47.245Z] at CancelRequestTest$HTTPSlowHandler.handle(CancelRequestTest.java:629) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpChain$Http2Chain.doFilter(HttpServerAdapters.java:477) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestServer$Http2TestContext.handle(HttpServerAdapters.java:932) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.doHandle(HttpServerAdapters.java:394) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.common.HttpServerAdapters$HttpTestHandler.lambda$toHttp2Handler$1(HttpServerAdapters.java:390) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.handleRequest(Http2TestServerConnection.java:691) [2024-08-10T07:54:47.245Z] at jdk.httpclient.test.lib.http2.Http2TestServerConnection.lambda$createStream$3(Http2TestServerConnection.java:642) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.245Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.245Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.245Z] config CancelRequestTest.teardown(): success [2024-08-10T07:54:47.245Z] [2024-08-10T07:54:47.245Z] =============================================== [2024-08-10T07:54:47.245Z] java/net/httpclient/CancelRequestTest.java [2024-08-10T07:54:47.245Z] Total tests run: 56, Passes: 39, Failures: 1, Skips: 16 [2024-08-10T07:54:47.245Z] =============================================== [2024-08-10T07:54:47.245Z] [2024-08-10T07:54:47.245Z] STDERR: [2024-08-10T07:54:47.245Z] DEBUG: [MainThread] [31ms] HttpClientImpl(1) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.245Z] DEBUG: [MainThread] [48ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:43831/http1/x/new/interrupt/get GET [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [121ms] Exchange establishing exchange for http://127.0.0.1:43831/http1/x/new/interrupt/get GET, [2024-08-10T07:54:47.245Z] proxy=null [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [152ms] Http2ClientImpl not found in connection pool [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [159ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.245Z] DEBUG: [MainThread] [165ms] Exchange cancel exchImpl: null, with "java.io.IOException: Request cancelled" [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [169ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [170ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [201ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [201ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [262ms] Exchange Cancelling exchImpl: HTTP/1.1 http://127.0.0.1:43831/http1/x/new/interrupt/get GET [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [262ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: java.io.IOException: Request cancelled [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [263ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [264ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [272ms] PlainHttpConnection(SocketTube(1)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [272ms] SocketTube(1) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [273ms] SocketTube(1) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [273ms] SocketTube(1) error raised before subscriber subscribed: java.io.IOException: connection closed locally [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [274ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [289ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [315ms] HttpClientImpl(1) ClientImpl (async) elapsed 245 millis for GET to http://127.0.0.1:43831/http1/x/new/interrupt/get [2024-08-10T07:54:47.245Z] DEBUG: [MainThread] [337ms] HttpClientImpl(2) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.245Z] DEBUG: [MainThread] [338ms] HttpClientImpl(2) ClientImpl (async) send http://127.0.0.1:43831/http1/x/new/interrupt/get GET [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [339ms] Exchange establishing exchange for http://127.0.0.1:43831/http1/x/new/interrupt/get GET, [2024-08-10T07:54:47.245Z] proxy=null [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [339ms] Http2ClientImpl not found in connection pool [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [344ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [344ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-10T07:54:47.245Z] DEBUG: [pool-1-thread-1] [344ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [344ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [345ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [345ms] Exchange checkFor407: all clear [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [345ms] Http1Exchange Sending headers only [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [360ms] Http1AsyncReceiver(SocketTube(2)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@56736c0d queue.isEmpty: true [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [392ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [392ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [393ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [393ms] PlainHttpConnection(SocketTube(2)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [393ms] SocketTube(2) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [393ms] SocketTube(2) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [393ms] SocketTube(2) error raised before subscriber subscribed: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [394ms] Http1AsyncReceiver(SocketTube(2)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@56736c0d, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [394ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [400ms] Http1AsyncReceiver(SocketTube(2)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [413ms] Http1AsyncReceiver(SocketTube(2)) downstream subscription demand is 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [413ms] Http1AsyncReceiver(SocketTube(2)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [413ms] Http1Exchange response created in advance [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [413ms] Http1Exchange initiating connect async [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [426ms] Exchange checkFor407: no response - java.net.ConnectException [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [440ms] MultiExchange MultiExchange interrupted with: java.net.ConnectException [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [440ms] HttpClientImpl(2) ClientImpl (async) elapsed 101 millis for GET to http://127.0.0.1:43831/http1/x/new/interrupt/get [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [441ms] HttpClientImpl(3) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [442ms] HttpClientImpl(3) ClientImpl (async) send http://127.0.0.1:43831/http1/x/new/interrupt/get GET [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] Exchange establishing exchange for http://127.0.0.1:43831/http1/x/new/interrupt/get GET, [2024-08-10T07:54:47.246Z] proxy=null [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] Http2ClientImpl not found in connection pool [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [443ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Exchange checkFor407: all clear [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1Exchange Sending headers only [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@38458646 queue.isEmpty: true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@38458646, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) downstream subscription demand is 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1AsyncReceiver(SocketTube(3)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1Exchange response created in advance [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [444ms] Http1Exchange initiating connect async [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [446ms] PlainHttpConnection(SocketTube(3)) registering connect event [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-3-SelectorManager] [464ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@137a1e36 for 8 (true) [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] HttpClientImpl(3) ClientImpl (async) elapsed 24 millis for GET to http://127.0.0.1:43831/http1/x/new/interrupt/get [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [466ms] Http1Exchange http://127.0.0.1:43831/http1/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [467ms] PlainHttpConnection(SocketTube(3)) Closing channel: channel registered with selector, key.interestOps=8, sa.interestOps=8 [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [467ms] SocketTube(3) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [467ms] SocketTube(3) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [467ms] SocketTube(3) error raised before subscriber subscribed: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [480ms] HttpClientImpl(4) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [506ms] HttpClientImpl(4) ClientImpl (async) send https://127.0.0.1:39871/https1/x/new/interrupt/get GET [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [506ms] Exchange establishing exchange for https://127.0.0.1:39871/https1/x/new/interrupt/get GET, [2024-08-10T07:54:47.246Z] proxy=null [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [508ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [509ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [509ms] PlainHttpConnection(SocketTube(4)) registering connect event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [511ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [512ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@51e727f4 for 8 (true) [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [512ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: finishing connect [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-3-SelectorManager] [513ms] PlainHttpConnection(SocketTube(3)) ConnectEvent: finishing connect [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [513ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:44292 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-3-SelectorManager] [514ms] SelectorAttachment key cancelled for java.nio.channels.SocketChannel[closed] [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [569ms] SocketTube(4) connecting flows [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [570ms] SocketTube(4) read publisher got subscriber [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [570ms] SocketTube(4) registering subscribe event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [570ms] SocketTube(4) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [571ms] SSL Writer(SocketTube(4)) requesting 1 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [571ms] SocketTube(4) subscribe event raised [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [571ms] SSLTube(SocketTube(4)) request: n=1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [571ms] SSL Writer(SocketTube(4)) calling downstreamSubscriber::onSubscribe on SocketTube(4) [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [571ms] SocketTube(4) subscribed for writing [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [572ms] SocketTube(4) write: registering startSubscription event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [572ms] SSL Writer(SocketTube(4)) onSubscribe initiating handshaking [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] Exchange cancel exchImpl: null, with "java.io.IOException: Request cancelled" [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] PlainHttpConnection(SocketTube(4)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] SocketTube(4) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] SocketTube(4) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [576ms] HttpClientImpl(4) ClientImpl (async) elapsed 70 millis for GET to https://127.0.0.1:39871/https1/x/new/interrupt/get [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [580ms] HttpClientImpl(5) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [580ms] HttpClientImpl(5) ClientImpl (async) send https://127.0.0.1:39871/https1/x/new/interrupt/get GET [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [587ms] SSL Writer(SocketTube(4)) added 1 (0 bytes) to the writeList [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [592ms] Exchange establishing exchange for https://127.0.0.1:39871/https1/x/new/interrupt/get GET, [2024-08-10T07:54:47.246Z] proxy=null [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [593ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [593ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [593ms] PlainHttpConnection(SocketTube(5)) registering connect event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [593ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-5-SelectorManager] [598ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@a20d368 for 8 (true) [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-5-SelectorManager] [599ms] PlainHttpConnection(SocketTube(5)) ConnectEvent: finishing connect [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-5-SelectorManager] [599ms] PlainHttpConnection(SocketTube(5)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:44300 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) connecting flows [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) read publisher got subscriber [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) registering subscribe event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SSL Writer(SocketTube(5)) requesting 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SSLTube(SocketTube(5)) request: n=1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SSL Writer(SocketTube(5)) calling downstreamSubscriber::onSubscribe on SocketTube(5) [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) subscribed for writing [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SocketTube(5) write: registering startSubscription event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SSL Writer(SocketTube(5)) onSubscribe initiating handshaking [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [601ms] SSL Writer(SocketTube(5)) added 1 (0 bytes) to the writeList [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-5-SelectorManager] [604ms] SocketTube(5) subscribe event raised [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] Exchange cancel exchImpl: null, with "java.io.IOException: Request cancelled" [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] PlainHttpConnection(SocketTube(5)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] SocketTube(5) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] SocketTube(5) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [642ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [643ms] HttpClientImpl(5) ClientImpl (async) elapsed 62 millis for GET to https://127.0.0.1:39871/https1/x/new/interrupt/get [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [643ms] HttpClientImpl(6) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [646ms] SSL Writer(SocketTube(5)) processData, writeList remaining:0, hsTriggered:true, needWrap:false [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-1] [646ms] SSL Writer(SocketTube(5)) wrapping 0 bytes [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [658ms] HttpClientImpl(6) ClientImpl (async) send https://127.0.0.1:39871/https1/x/new/interrupt/get GET [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [660ms] Exchange establishing exchange for https://127.0.0.1:39871/https1/x/new/interrupt/get GET, [2024-08-10T07:54:47.246Z] proxy=null [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [661ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [662ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [662ms] PlainHttpConnection(SocketTube(6)) registering connect event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [669ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [683ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@5f5415f for 8 (true) [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [684ms] PlainHttpConnection(SocketTube(6)) ConnectEvent: finishing connect [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [684ms] PlainHttpConnection(SocketTube(6)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:44302 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [684ms] SocketTube(6) connecting flows [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [685ms] SocketTube(6) read publisher got subscriber [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [685ms] SocketTube(6) registering subscribe event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [687ms] SocketTube(6) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [687ms] SocketTube(6) subscribe event raised [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [688ms] SSL Writer(SocketTube(6)) requesting 1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [688ms] SSLTube(SocketTube(6)) request: n=1 [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [688ms] SSL Writer(SocketTube(6)) calling downstreamSubscriber::onSubscribe on SocketTube(6) [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [688ms] SocketTube(6) subscribed for writing [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [688ms] SocketTube(6) write: registering startSubscription event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [700ms] SSL Writer(SocketTube(6)) onSubscribe initiating handshaking [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [700ms] SSL Writer(SocketTube(6)) added 1 (0 bytes) to the writeList [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [700ms] SSL Writer(SocketTube(6)) processData, writeList remaining:0, hsTriggered:true, needWrap:false [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-3] [700ms] SSL Writer(SocketTube(6)) wrapping 0 bytes [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] Exchange cancel exchImpl: null, with "java.io.IOException: Request cancelled" [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] PlainHttpConnection(SocketTube(6)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] SocketTube(6) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] SocketTube(6) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [708ms] HttpClientImpl(6) ClientImpl (async) elapsed 50 millis for GET to https://127.0.0.1:39871/https1/x/new/interrupt/get [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [708ms] SocketTube(4) handling pending subscription for READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 0 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@2fc9254d[Not completed, 4 dependents] (id=136) downstreamSubscription: SubscriptionBase: window = 0 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(4)), delegate: null, getALPN: null, onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=0 lim=0 cap=1024], count: 0, scheduler: running, status: null, handshakeState: 0, engine: NOT_HANDSHAKING [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [708ms] SocketTube(4) read demand reset to 0 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [708ms] SocketTube(4) calling onSubscribe [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [709ms] SSL Reader(SocketTube(4)) requesting 1 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [709ms] SocketTube(4) got some demand for reading [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [709ms] SocketTube(4) resuming read event [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [709ms] SSL Writer(SocketTube(4)) processData, writeList remaining:0, hsTriggered:true, needWrap:false [2024-08-10T07:54:47.246Z] DEBUG: [pool-1-thread-2] [709ms] SSL Writer(SocketTube(4)) wrapping 0 bytes [2024-08-10T07:54:47.246Z] DEBUG: [MainThread] [711ms] HttpClientImpl(7) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [711ms] SocketTube(4) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SSL Reader(SocketTube(4)) calling downstreamSubscriber::onSubscribe on SSLSubscriberWrapper[SSLTube(SocketTube(4)), delegate: null, getALPN: null, onCompleteReceived: false, onError: null] [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SSLTube(SocketTube(4)) SSLSubscriberWrapper (reader) onSubscribe(SubscriptionBase: window = 0 cancelled = false) [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SSLTube(SocketTube(4)) SSLSubscriberWrapper (reader) onSubscribeImpl: no delegate yet [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SocketTube(4) onSubscribe called [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SocketTube(4) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-4-SelectorManager] [712ms] SSL Reader(SocketTube(4)) onError: java.io.IOException: connection closed locally [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) handling pending subscription for READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 0 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@f0d2a2f[Not completed, 4 dependents] (id=214) downstreamSubscription: SubscriptionBase: window = 0 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(6)), delegate: null, getALPN: null, onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=0 lim=0 cap=1024], count: 0, scheduler: running, status: null, handshakeState: 0, engine: NOT_HANDSHAKING [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) read demand reset to 0 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) calling onSubscribe [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SSL Reader(SocketTube(6)) requesting 1 [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) got some demand for reading [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) resuming read event [2024-08-10T07:54:47.246Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SSL Reader(SocketTube(6)) calling downstreamSubscriber::onSubscribe on SSLSubscriberWrapper[SSLTube(SocketTube(6)), delegate: null, getALPN: null, onCompleteReceived: false, onError: null] [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SSLTube(SocketTube(6)) SSLSubscriberWrapper (reader) onSubscribe(SubscriptionBase: window = 0 cancelled = false) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SSLTube(SocketTube(6)) SSLSubscriberWrapper (reader) onSubscribeImpl: no delegate yet [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) onSubscribe called [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SocketTube(6) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-6-SelectorManager] [726ms] SSL Reader(SocketTube(6)) onError: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [733ms] HttpClientImpl(7) ClientImpl (async) send http://127.0.0.1:35867/http2/x/new/interrupt/get GET [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [745ms] Exchange establishing exchange for http://127.0.0.1:35867/http2/x/new/interrupt/get GET, [2024-08-10T07:54:47.247Z] proxy=null [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [745ms] Http2ClientImpl not found in connection pool [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [745ms] ExchangeImpl get: Trying to get HTTP/2 connection [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [746ms] ExchangeImpl handling HTTP/2 connection creation result [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [746ms] ExchangeImpl new Http1Exchange, try to upgrade [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [746ms] PlainHttpConnection(?) Initial receive buffer size is: 65536 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [746ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Exchange checkFor407: all clear [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1Exchange Sending headers only [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@6ed2360e queue.isEmpty: true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@6ed2360e, demand=1, canRequestMore=true, queue.isEmpty=true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) downstream subscription demand is 1 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) downstream subscription demand is 1 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1AsyncReceiver(SocketTube(7)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1Exchange response created in advance [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [758ms] Http1Exchange initiating connect async [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [759ms] PlainHttpConnection(SocketTube(7)) registering connect event [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [764ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@7dd79c09 for 8 (true) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [764ms] PlainHttpConnection(SocketTube(7)) ConnectEvent: finishing connect [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [764ms] PlainHttpConnection(SocketTube(7)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:40148 [2024-08-10T07:54:47.247Z] TestServer: New connection from Socket[addr=/127.0.0.1,port=40148,localport=35867] [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [773ms] PlainHttpConnection(SocketTube(7)) finishConnect, setting connected=true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] Http1Exchange SocketTube(7) connecting flows [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) connecting flows [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) read publisher got subscriber [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) registering subscribe event [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] Http1Publisher(SocketTube(7)) got subscriber: SocketTube(7) [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) subscribed for writing [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] SocketTube(7) write: registering startSubscription event [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [774ms] Http1Exchange requestAction.headers [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [784ms] SocketTube(7) subscribe event raised [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [784ms] SocketTube(7) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@772ff779 [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [784ms] SocketTube(7) read demand reset to 0 [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [784ms] SocketTube(7) calling onSubscribe [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [786ms] Http1AsyncReceiver(SocketTube(7)) Received onSubscribed from upstream [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [787ms] Http1Exchange http://127.0.0.1:35867/http2/x/new/interrupt/get: java.io.IOException: Request cancelled [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [787ms] Http1Exchange http://127.0.0.1:35867/http2/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [787ms] Http1Exchange http://127.0.0.1:35867/http2/x/new/interrupt/get: completed cf with java.io.IOException: Request cancelled [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [788ms] PlainHttpConnection(SocketTube(7)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [788ms] SocketTube(7) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [788ms] SocketTube(7) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] Server connection to /127.0.0.1:40148 stopping. 0 streams [2024-08-10T07:54:47.247Z] TestServer: start exception: java.io.IOException: Connection closed [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [794ms] Http1Exchange setting outgoing with headers [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [797ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=237 cap=237]], throwable=null] [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [806ms] Exchange checkFor407: no response - java.io.IOException: Request cancelled [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [806ms] MultiExchange MultiExchange interrupted with: java.io.IOException: Request cancelled [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-4] [806ms] HttpClientImpl(7) ClientImpl (async) elapsed 73 millis for GET to http://127.0.0.1:35867/http2/x/new/interrupt/get [2024-08-10T07:54:47.247Z] DEBUG: [MainThread] [806ms] HttpClientImpl(8) proxySelector is java.net.ProxySelector$StaticProxySelector@64dc7dd4 (user-supplied=true) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [812ms] SocketTube(7) onSubscribe called [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [812ms] SocketTube(7) pending subscriber subscribed [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [812ms] SocketTube(7) pausing read event [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] Http1AsyncReceiver(SocketTube(7)) downstream subscription demand is 1 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] Http1AsyncReceiver(SocketTube(7)) checkRequestMore: canRequestMore=true, hasDemand=true [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] Http1AsyncReceiver(SocketTube(7)) Http1TubeSubscriber: requesting one more from upstream [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] SocketTube(7) got some demand for reading [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] SocketTube(7) resuming read event [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-5] [812ms] SocketTube(7) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [813ms] SocketTube(7) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@772ff779 [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [813ms] SocketTube(7) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [813ms] Http1AsyncReceiver(SocketTube(7)) onError: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-7-SelectorManager] [814ms] Http1AsyncReceiver(SocketTube(7)) recorded jdk.internal.net.http.common.ConnectionExpiredException: subscription is finished [2024-08-10T07:54:47.247Z] delegate: jdk.internal.net.http.Http1Response$HeadersReader@6ed2360e queue.isEmpty: true jdk.internal.net.http.common.ConnectionExpiredException: subscription is finished [2024-08-10T07:54:47.247Z] jdk.internal.net.http.common.ConnectionExpiredException: subscription is finished [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.onReadError(Http1AsyncReceiver.java:490) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber.onError(Http1AsyncReceiver.java:590) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadSubscription.signalCompletion(SocketTube.java:637) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:821) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$TryEndDeferredCompleter.complete(SequentialScheduler.java:347) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:186) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.handleSubscribeEvent(SocketTube.java:698) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.AsyncTriggerEvent.handle(AsyncTriggerEvent.java:54) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:840) [2024-08-10T07:54:47.247Z] Caused by: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http1Exchange.cancelImpl(Http1Exchange.java:501) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http1Exchange.cancel(Http1Exchange.java:418) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Exchange.cancel(Exchange.java:221) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.MultiExchange.cancel(MultiExchange.java:284) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.MultiExchange$CancelableRef.cancel(MultiExchange.java:193) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.common.MinimalFuture.cancel(MinimalFuture.java:107) [2024-08-10T07:54:47.247Z] at CancelRequestTest.testGetSendAsync(CancelRequestTest.java:320) [2024-08-10T07:54:47.247Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.247Z] at java.base/jdk. [2024-08-10T07:54:47.247Z] [2024-08-10T07:54:47.247Z] ... [2024-08-10T07:54:47.247Z] Output overflow: [2024-08-10T07:54:47.247Z] JT Harness has limited the test output to the text [2024-08-10T07:54:47.247Z] at the beginning and the end, so that you can see how the [2024-08-10T07:54:47.247Z] test began, and how it completed. [2024-08-10T07:54:47.247Z] [2024-08-10T07:54:47.247Z] If you need to see more of the output from the test, [2024-08-10T07:54:47.247Z] set the system property javatest.maxOutputSize to a higher [2024-08-10T07:54:47.247Z] value. The current value is 100000 [2024-08-10T07:54:47.247Z] ... [2024-08-10T07:54:47.247Z] [2024-08-10T07:54:47.247Z] Manager] [16s 286ms] SSL Writer(SocketTube(65)) pushScheduler is alive [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Writer(SocketTube(65)) DownstreamPusher: queue not empty, downstreamSubscription: SubscriptionBase: window = 0 cancelled = false [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Writer(SocketTube(65)) processData, writeList remaining:0, hsTriggered:false, needWrap:false [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] Http2Connection(SSLTube(SocketTube(65))) Shutting down h2c (closed=false): java.io.EOFException: HTTP/2 client stopped [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] Http2ClientImpl removing from the connection pool: Http2Connection(SSLTube(SocketTube(65))) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] Http2ClientImpl removed from the connection pool: Http2Connection(SSLTube(SocketTube(65))) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] PlainHttpConnection(SocketTube(65)) Closing channel: channel not registered with selector [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) pausing read event [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) Sending error java.io.IOException: connection closed locally to subscriber READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 1 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@5eb9d658[Not completed, 4 dependents] (id=4321) downstreamSubscription: SubscriptionBase: window = 9223372036854775802 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(65)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@72cc0524, getALPN: jdk.internal.net.http.common.MinimalFuture@3a71041a[Completed normally] (id=4327), onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=80 lim=80 cap=2048], count: 97, scheduler: running, status: CLOSED, handshakeState: 0, engine: NOT_HANDSHAKING [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) forwarding error to subscriber: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Reader(SocketTube(65)) onError: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Reader(SocketTube(65)) error java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.AsyncSSLConnection.close(AsyncSSLConnection.java:111) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2Connection.shutdown(Http2Connection.java:713) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:199) [2024-08-10T07:54:47.247Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:193) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:349) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:774) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:962) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Reader(SocketTube(65)) DownstreamPusher: forwarding error downstream: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSLTube(SocketTube(65)) SSLSubscriberWrapper[SSLTube(SocketTube(65)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@72cc0524, getALPN: jdk.internal.net.http.common.MinimalFuture@3a71041a[Completed normally] (id=4327), onCompleteReceived: false, onError: java.io.IOException: connection closed locally]: onErrorImpl: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] Http2Connection(SSLTube(SocketTube(65))) onError: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSLTube(SocketTube(65)) subscriber completed with error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] AsyncSSLConnection(SSLTube(SocketTube(65))) HttpPublisher: cancelled by SSLTube(SocketTube(65)) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Reader(SocketTube(65)) stop [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SSL Writer(SocketTube(65)) stop [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) Stopping read scheduler [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) leaving read() loop with error: Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-48-SelectorManager] [16s 286ms] SocketTube(65) Read scheduler stopped [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-1] [16s 286ms] Http2Connection(SSLTube(SocketTube(65))) Stopping scheduler java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.AsyncSSLConnection.close(AsyncSSLConnection.java:111) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2Connection.shutdown(Http2Connection.java:713) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:199) [2024-08-10T07:54:47.247Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:193) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:349) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:774) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:962) [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-1] [16s 286ms] Http2Connection(SSLTube(SocketTube(65))) Shutting down h2c (closed=true): java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-3] [16s 286ms] SocketTube(65) leaving request(1): Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.247Z] java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.AsyncSSLConnection.close(AsyncSSLConnection.java:111) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2Connection.shutdown(Http2Connection.java:713) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:199) [2024-08-10T07:54:47.247Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:193) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:349) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:774) [2024-08-10T07:54:47.247Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:962) [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-6] [16s 287ms] Http2Connection(SSLTube(SocketTube(66))) Shutting down h2c (closed=true): java.io.IOException: connection closed locally [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 0 (false) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SocketTube(82) read bytes: 40 [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SSL Reader(SocketTube(82)) onNext [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SSL Reader(SocketTube(82)) Adding 40 bytes to read buffer [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SocketTube(82) resuming read event [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 1 (false) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SocketTube(82) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-6] [16s 287ms] SSL Reader(SocketTube(82)) processData: readBuf remaining:40, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-6] [16s 287ms] SSL Reader(SocketTube(82)) Unwrapping: 40 [2024-08-10T07:54:47.247Z] DEBUG: [pool-1-thread-6] [16s 287ms] SSLFlowDelegate(SocketTube(82)) doClosure(Status = CLOSED HandshakeStatus = NEED_WRAP [2024-08-10T07:54:47.247Z] bytesConsumed = 40 bytesProduced = 0): NEED_WRAP [isOutboundDone: false, isInboundDone: true] [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 0 (false) [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SocketTube(82) no more demand for reading [2024-08-10T07:54:47.247Z] DEBUG: [HttpClient-59-SelectorManager] [16s 287ms] SocketTube(82) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 287ms] SSLFlowDelegate(SocketTube(82)) doClosure: close_notify received [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 287ms] SocketTube(65) write: requesting more... [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 287ms] SSL Writer(SocketTube(65)) DownstreamPusher: queue not empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 287ms] SSL Writer(SocketTube(65)) DownstreamPusher: Pushing 40 bytes downstream [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] SocketTube(65) trying to write: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] SocketTube(65) write error: java.nio.channels.ClosedChannelException [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] SocketTube(65) error signalled java.nio.channels.ClosedChannelException [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] SocketTube(65) write: cancel [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] SocketTube(65) write: resetting demand to 0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 287ms] SSL Writer(SocketTube(82)) processData, writeList remaining:0, hsTriggered:true, needWrap:true [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) wrapping 0 bytes [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) SSLResult: Status = CLOSED HandshakeStatus = NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] bytesConsumed = 0 bytesProduced = 40 sequenceNumber = 4 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) CLOSED [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) OK => produced: 40 bytes into 40, not wrapped: 0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) wrapBuffer returned Status = CLOSED HandshakeStatus = NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] bytesConsumed = 0 bytesProduced = 40 sequenceNumber = 4 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] AsyncSSLConnection(SSLTube(SocketTube(82))) HttpPublisher: cancelled by SSLTube(SocketTube(82)) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) Sending 40 bytes downstream [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) Adding 40 to outputQ queue [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) pushScheduler is alive [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) DownstreamPusher: queue not empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) DownstreamPusher: Pushing 40 bytes downstream [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SocketTube(82) trying to write: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SocketTube(82) wrote: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SocketTube(82) write: requesting more... [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SocketTube(82) leaving requestMore: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SocketTube(82) leaving w.onNext Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) upstreamWindowUpdate, downstreamQueueSize:0, upstreamWindow:1 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) completionAcknowledged upstreamCompleted:true, downstreamCompleted:false, closing:true [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) pushScheduler is alive [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 288ms] SSL Writer(SocketTube(82)) calling downstreamSubscriber.onComplete() [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SocketTube(82) write completed, 0 yet to send [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SocketTube(82) InternalWriteSubscriber::onComplete Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Writer(SocketTube(82)) processData, writeList remaining:0, hsTriggered:false, needWrap:false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) Unwrapped: result: Status = CLOSED HandshakeStatus = NEED_WRAP [2024-08-10T07:54:47.248Z] bytesConsumed = 40 bytesProduced = 0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) Unwrapped: consumed: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) requesting 1 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SocketTube(82) got some demand for reading [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SocketTube(82) resuming read event [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 1 (true) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 0 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) got read EOF [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) pausing read event [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@68c8349d for 0 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) completing subscriber [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SSL Reader(SocketTube(82)) upstream completed: READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 1 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@52ac82c8[Not completed, 4 dependents] (id=5470) downstreamSubscription: SubscriptionBase: window = 9223372036854775798 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(82)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@7111c9d5, getALPN: jdk.internal.net.http.common.MinimalFuture@17ae06f9[Completed normally] (id=5476), onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=40 lim=40 cap=2048], count: 171, scheduler: running, status: CLOSED, handshakeState: 0, engine: NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SSL Reader(SocketTube(82)) Adding 0 bytes to read buffer [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SSL Reader(SocketTube(82)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 9223372036854775798 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) Stopping read scheduler [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) leaving read() loop after EOF: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-59-SelectorManager] [16s 289ms] SocketTube(82) Read scheduler stopped [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SocketTube(82) leaving request(1): Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) processData: readBuf remaining:0, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) completing [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) completionAcknowledged upstreamCompleted:true, downstreamCompleted:false, closing:false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) pushScheduler is alive [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 9223372036854775798 cancelled = false [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSL Reader(SocketTube(82)) calling downstreamSubscriber.onComplete() [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] SSLTube(SocketTube(82)) DelegateWrapper: completing subscriber [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] Http2Connection(SSLTube(SocketTube(82))) Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 289ms] Http2Connection(SSLTube(SocketTube(82))) Stopping scheduler java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.248Z] java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.Http2Connection$Http2TubeSubscriber.onComplete(Http2Connection.java:1372) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SSLTube$DelegateWrapper.onComplete(SSLTube.java:276) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.complete(SSLTube.java:440) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.onComplete(SSLTube.java:541) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.checkCompletion(SubscriberWrapper.java:472) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run1(SubscriberWrapper.java:334) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run(SubscriberWrapper.java:259) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:232) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(SSLFlowDelegate.java:527) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(SSLFlowDelegate.java:282) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$TryEndDeferredCompleter.complete(SequentialScheduler.java:347) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:151) [2024-08-10T07:54:47.248Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2024-08-10T07:54:47.248Z] at CancelRequestTest$TestExecutor.lambda$execute$0(CancelRequestTest.java:140) [2024-08-10T07:54:47.248Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.248Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.248Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] Http2Connection(SSLTube(SocketTube(82))) Shutting down h2c (closed=false): java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] Http2ClientImpl removing from the connection pool: Http2Connection(SSLTube(SocketTube(82))) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] Http2ClientImpl removed from the connection pool: Http2Connection(SSLTube(SocketTube(82))) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] PlainHttpConnection(SocketTube(82)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] SocketTube(82) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] SocketTube(82) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] SSLTube(SocketTube(82)) subscriber completed normally [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] AsyncSSLConnection(SSLTube(SocketTube(82))) HttpPublisher: cancelled by SSLTube(SocketTube(82)) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] SSL Reader(SocketTube(82)) stop [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-6] [16s 290ms] SSL Writer(SocketTube(82)) stop [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 288ms] AsyncSSLConnection(SSLTube(SocketTube(65))) HttpPublisher: cancelled by SSLTube(SocketTube(65)) [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SocketTube(65) leaving w.onNext Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SSL Writer(SocketTube(65)) upstreamWindowUpdate, downstreamQueueSize:0, upstreamWindow:1 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SSL Writer(SocketTube(65)) calling downstreamSubscriber.onComplete() [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SocketTube(65) write completed, 40 yet to send [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SocketTube(65) InternalWriteSubscriber::onComplete Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 291ms] SocketTube(65) leaving requestMore: Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=0] [2024-08-10T07:54:47.248Z] Server connection to /127.0.0.1:59742 stopping. 1 streams [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SocketTube(83) read bytes: 40 [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SSL Reader(SocketTube(83)) onNext [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SSL Reader(SocketTube(83)) Adding 40 bytes to read buffer [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SocketTube(83) resuming read event [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 1 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SocketTube(83) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SocketTube(83) no more demand for reading [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 306ms] SocketTube(83) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 307ms] SSL Reader(SocketTube(83)) processData: readBuf remaining:40, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 307ms] SSL Reader(SocketTube(83)) Unwrapping: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 307ms] SSL Reader(SocketTube(83)) Decoded 0 bytes out of 40 into buffer of 40 remaining to decode: 0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Reader(SocketTube(83)) Unwrapped: result: Status = OK HandshakeStatus = NOT_HANDSHAKING [2024-08-10T07:54:47.248Z] bytesConsumed = 40 bytesProduced = 0 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Reader(SocketTube(83)) Unwrapped: consumed: 40 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Reader(SocketTube(83)) requesting 1 [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 308ms] SocketTube(83) got some demand for reading [2024-08-10T07:54:47.248Z] DEBUG: [pool-1-thread-7] [16s 308ms] SocketTube(83) resuming read event [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 1 (true) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SocketTube(83) read bytes: 40 [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SSL Reader(SocketTube(83)) onNext [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SSL Reader(SocketTube(83)) Adding 40 bytes to read buffer [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SocketTube(83) resuming read event [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 1 (false) [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SocketTube(83) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.248Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SocketTube(83) no more demand for reading [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 308ms] SocketTube(83) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SocketTube(83) leaving request(1): Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Reader(SocketTube(83)) processData: readBuf remaining:40, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Reader(SocketTube(83)) Unwrapping: 40 [2024-08-10T07:54:47.249Z] TestServer: Connection writer stopping [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSLFlowDelegate(SocketTube(83)) doClosure(Status = CLOSED HandshakeStatus = NEED_WRAP [2024-08-10T07:54:47.249Z] bytesConsumed = 40 bytesProduced = 0): NEED_WRAP [isOutboundDone: false, isInboundDone: true] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSLFlowDelegate(SocketTube(83)) doClosure: close_notify received [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) processData, writeList remaining:0, hsTriggered:true, needWrap:true [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) wrapping 0 bytes [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-46-SelectorManager] [16s 308ms] HttpClientImpl(46) SelectorManager shutting down [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) SSLResult: Status = CLOSED HandshakeStatus = NOT_HANDSHAKING [2024-08-10T07:54:47.249Z] bytesConsumed = 0 bytesProduced = 40 sequenceNumber = 3 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) CLOSED [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) OK => produced: 40 bytes into 40, not wrapped: 0 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] SSL Writer(SocketTube(83)) wrapBuffer returned Status = CLOSED HandshakeStatus = NOT_HANDSHAKING [2024-08-10T07:54:47.249Z] bytesConsumed = 0 bytesProduced = 40 sequenceNumber = 3 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 308ms] AsyncSSLConnection(SSLTube(SocketTube(83))) HttpPublisher: cancelled by SSLTube(SocketTube(83)) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) Sending 40 bytes downstream [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) Adding 40 to outputQ queue [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) pushScheduler is alive [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) DownstreamPusher: queue not empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) DownstreamPusher: Pushing 40 bytes downstream [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-46-SelectorManager] [16s 309ms] Http2ClientImpl stopping [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) trying to write: 40 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) wrote: 40 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) write: requesting more... [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) leaving requestMore: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) leaving w.onNext Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) upstreamWindowUpdate, downstreamQueueSize:0, upstreamWindow:1 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) completionAcknowledged upstreamCompleted:true, downstreamCompleted:false, closing:true [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) pushScheduler is alive [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) calling downstreamSubscriber.onComplete() [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) write completed, 0 yet to send [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) InternalWriteSubscriber::onComplete Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Writer(SocketTube(83)) processData, writeList remaining:0, hsTriggered:false, needWrap:false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Reader(SocketTube(83)) Unwrapped: result: Status = CLOSED HandshakeStatus = NEED_WRAP [2024-08-10T07:54:47.249Z] bytesConsumed = 40 bytesProduced = 0 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Reader(SocketTube(83)) Unwrapped: consumed: 40 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SSL Reader(SocketTube(83)) requesting 1 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) got some demand for reading [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 309ms] SocketTube(83) resuming read event [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 1 (true) [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) got read EOF [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) pausing read event [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@51defeee for 0 (false) [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) completing subscriber [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SSL Reader(SocketTube(83)) upstream completed: READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 1 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@602ba162[Not completed, 4 dependents] (id=5528) downstreamSubscription: SubscriptionBase: window = 9223372036854775805 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(83)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@7e41634f, getALPN: jdk.internal.net.http.common.MinimalFuture@25292303[Completed normally] (id=5534), onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=40 lim=40 cap=2048], count: 50, scheduler: running, status: CLOSED, handshakeState: 0, engine: NOT_HANDSHAKING [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SSL Reader(SocketTube(83)) Adding 0 bytes to read buffer [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SSL Reader(SocketTube(83)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 9223372036854775805 cancelled = false [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) Stopping read scheduler [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) leaving read() loop after EOF: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-60-SelectorManager] [16s 310ms] SocketTube(83) Read scheduler stopped [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SocketTube(83) leaving request(1): Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) processData: readBuf remaining:0, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) completing [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) completionAcknowledged upstreamCompleted:true, downstreamCompleted:false, closing:false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) pushScheduler is alive [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) DownstreamPusher: queue empty, downstreamSubscription: SubscriptionBase: window = 9223372036854775805 cancelled = false [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSL Reader(SocketTube(83)) calling downstreamSubscriber.onComplete() [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] SSLTube(SocketTube(83)) DelegateWrapper: completing subscriber [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 310ms] Http2Connection(SSLTube(SocketTube(83))) Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] Http2Connection(SSLTube(SocketTube(83))) Stopping scheduler java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.249Z] java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.Http2Connection$Http2TubeSubscriber.onComplete(Http2Connection.java:1372) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SSLTube$DelegateWrapper.onComplete(SSLTube.java:276) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.complete(SSLTube.java:440) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.onComplete(SSLTube.java:541) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.checkCompletion(SubscriberWrapper.java:472) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run1(SubscriberWrapper.java:334) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run(SubscriberWrapper.java:259) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:232) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(SSLFlowDelegate.java:527) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(SSLFlowDelegate.java:282) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$TryEndDeferredCompleter.complete(SequentialScheduler.java:347) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:151) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2024-08-10T07:54:47.249Z] at CancelRequestTest$TestExecutor.lambda$execute$0(CancelRequestTest.java:140) [2024-08-10T07:54:47.249Z] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [2024-08-10T07:54:47.249Z] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [2024-08-10T07:54:47.249Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] Http2Connection(SSLTube(SocketTube(83))) Shutting down h2c (closed=false): java.io.EOFException: Idle connection closed by HTTP/2 peer [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] Http2ClientImpl removing from the connection pool: Http2Connection(SSLTube(SocketTube(83))) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] Http2ClientImpl removed from the connection pool: Http2Connection(SSLTube(SocketTube(83))) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] PlainHttpConnection(SocketTube(83)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0 [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] SocketTube(83) signal read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] SocketTube(83) got read error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] SSLTube(SocketTube(83)) subscriber completed normally [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] AsyncSSLConnection(SSLTube(SocketTube(83))) HttpPublisher: cancelled by SSLTube(SocketTube(83)) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] SSL Reader(SocketTube(83)) stop [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-7] [16s 311ms] SSL Writer(SocketTube(83)) stop [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SSLTube(SocketTube(64)) subscriber completed with error: java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] AsyncSSLConnection(SSLTube(SocketTube(64))) HttpPublisher: cancelled by SSLTube(SocketTube(64)) [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SSL Reader(SocketTube(64)) stop [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SSL Writer(SocketTube(64)) stop [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SocketTube(64) Stopping read scheduler [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SocketTube(64) leaving read() loop with error: Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [HttpClient-47-SelectorManager] [16s 318ms] SocketTube(64) Read scheduler stopped [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-4] [16s 318ms] SocketTube(64) leaving request(1): Reading: [ops=0, demand=1, stopped=true], Writing: [ops=0, demand=1] [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-8] [16s 319ms] Http2Connection(SSLTube(SocketTube(64))) Stopping scheduler java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:159) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:372) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.AsyncSSLConnection.close(AsyncSSLConnection.java:111) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.Http2Connection.shutdown(Http2Connection.java:713) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:199) [2024-08-10T07:54:47.249Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:193) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:349) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:774) [2024-08-10T07:54:47.249Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:962) [2024-08-10T07:54:47.249Z] DEBUG: [pool-1-thread-8] [16s 319ms] Http2Connection(SSLTube(SocketTube(64))) Shutting down h2c (closed=true): java.io.IOException: connection closed locally [2024-08-10T07:54:47.249Z] java.lang.Exception: failures: 1 [2024-08-10T07:54:47.249Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:104) [2024-08-10T07:54:47.249Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2024-08-10T07:54:47.249Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2024-08-10T07:54:47.249Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2024-08-10T07:54:47.249Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2024-08-10T07:54:47.249Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2024-08-10T07:54:47.249Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2024-08-10T07:54:47.249Z] at java.base/java.lang.Thread.run(Thread.java:840) [2024-08-10T07:54:47.249Z] [2024-08-10T07:54:47.249Z] JavaTest Message: Test threw exception: java.lang.Exception: failures: 1 [2024-08-10T07:54:47.249Z] JavaTest Message: shutting down test [2024-08-10T07:54:47.249Z] [2024-08-10T07:54:47.249Z] STATUS:Failed.`main' threw exception: java.lang.Exception: failures: 1 [2024-08-10T07:54:47.249Z] rerun: [2024-08-10T07:54:47.249Z] cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/scratch/2 && \ [2024-08-10T07:54:47.249Z] DISPLAY=:0 \ [2024-08-10T07:54:47.249Z] HOME=/home/jenkins \ [2024-08-10T07:54:47.249Z] PATH=/bin:/usr/bin:/usr/sbin \ [2024-08-10T07:54:47.250Z] CLASSPATH=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/javatest.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jvmtest/openjdk/jtreg/lib/jtreg.jar \ [2024-08-10T07:54:47.250Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image/bin/java \ [2024-08-10T07:54:47.250Z] -Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2024-08-10T07:54:47.250Z] -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2024-08-10T07:54:47.250Z] -Dtest.compiler.opts= \ [2024-08-10T07:54:47.250Z] -Dtest.java.opts= \ [2024-08-10T07:54:47.250Z] -Dtest.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image \ [2024-08-10T07:54:47.250Z] -Dcompile.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/j2sdk-image \ [2024-08-10T07:54:47.250Z] -Dtest.timeout.factor=8.0 \ [2024-08-10T07:54:47.250Z] -Dtest.nativepath=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-10T07:54:47.250Z] -Dtest.root=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2024-08-10T07:54:47.250Z] -Dtest.name=java/net/httpclient/CancelRequestTest.java \ [2024-08-10T07:54:47.250Z] -Dtest.file=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/CancelRequestTest.java \ [2024-08-10T07:54:47.250Z] -Dtest.src=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient \ [2024-08-10T07:54:47.250Z] -Dtest.src.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.250Z] -Dtest.classes=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d \ [2024-08-10T07:54:47.250Z] -Dtest.class.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.250Z] -Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/java/net/httpclient/CancelRequestTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/classes/1/test/jdk/java/net/httpclient/lib \ [2024-08-10T07:54:47.250Z] -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-10T07:54:47.250Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2024-08-10T07:54:47.250Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2024-08-10T07:54:47.250Z] -ea \ [2024-08-10T07:54:47.250Z] -esa \ [2024-08-10T07:54:47.250Z] -Xmx512m \ [2024-08-10T07:54:47.250Z] -XX:-UseCompressedOops \ [2024-08-10T07:54:47.250Z] -Djava.awt.headless=true \ [2024-08-10T07:54:47.250Z] -Djava.library.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2024-08-10T07:54:47.250Z] -Djdk.internal.httpclient.debug=true \ [2024-08-10T07:54:47.250Z] -Djdk.httpclient.enableAllMethodRetry=true \ [2024-08-10T07:54:47.250Z] com.sun.javatest.regtest.agent.MainWrapper /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work/java/net/httpclient/CancelRequestTest.d/testng.0.jta java/net/httpclient/CancelRequestTest.java false CancelRequestTest [2024-08-10T07:54:47.250Z] [2024-08-10T07:54:47.250Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.Exception: failures: 1 [2024-08-10T07:54:47.250Z] -------------------------------------------------- [2024-08-10T08:26:31.014Z] Test results: passed: 801; failed: 1 [2024-08-10T08:26:46.632Z] Report written to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/report/html/report.html [2024-08-10T08:26:46.632Z] Results written to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_x86-64_alpine-linux_testList_4/aqa-tests/TKG/output_1723273565654/jdk_net_1/work [2024-08-10T08:26:46.632Z] Error: Some tests failed or other problems occurred. [2024-08-10T08:26:46.632Z] ----------------------------------- [2024-08-10T08:26:46.632Z] jdk_net_1_FAILED [2024-08-10T08:26:46.632Z] ----------------------------------- [2024-08-10T08:26:46.632Z] [2024-08-10T08:26:46.632Z] TEST TEARDOWN: [2024-08-10T08:26:46.632Z] Nothing to be done for teardown. [2024-08-10T08:26:46.632Z] jdk_net_1 Finish Time: Sat Aug 10 08:26:45 2024 Epoch Time (ms): 1723278405186