[2025-11-06T06:36:26.521Z] Running test jdk_net_1 ... [2025-11-06T06:36:26.521Z] =============================================== [2025-11-06T06:36:26.521Z] jdk_net_1 Start Time: Thu Nov 6 01:36:19 2025 Epoch Time (ms): 1762410979842 [2025-11-06T06:36:26.521Z] variation: Mode650 [2025-11-06T06:36:26.521Z] JVM_OPTIONS: -XX:-UseCompressedOops [2025-11-06T06:36:26.521Z] { \ [2025-11-06T06:36:26.521Z] echo ""; echo "TEST SETUP:"; \ [2025-11-06T06:36:26.521Z] echo "Nothing to be done for setup."; \ [2025-11-06T06:36:26.521Z] mkdir -p "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1"; \ [2025-11-06T06:36:26.521Z] cd "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1"; \ [2025-11-06T06:36:26.521Z] echo ""; echo "TESTING:"; \ [2025-11-06T06:36:26.521Z] "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image/bin/java" -Xmx512m -jar "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../../jvmtest/openjdk/jtreg/lib/jtreg.jar" \ [2025-11-06T06:36:26.521Z] -agentvm -a -ea -esa -v:fail,error,time,nopass -retain:fail,error,*.dmp,javacore.*,heapdump.*,*.trc -ignore:quiet -timeoutFactor:8 -xml:verify -concurrency:1 -nativepath:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native" -vmoptions:"-Xmx512m -XX:-UseCompressedOops " \ [2025-11-06T06:36:26.521Z] -w ""/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1"/work" \ [2025-11-06T06:36:26.521Z] -r ""/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1"/report" \ [2025-11-06T06:36:26.521Z] -jdk:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image" \ [2025-11-06T06:36:26.521Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk/ProblemList.txt" \ [2025-11-06T06:36:26.521Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../../jvmtest/openjdk/excludes/ProblemList_openjdk17.txt" \ [2025-11-06T06:36:26.521Z] \ [2025-11-06T06:36:26.521Z] -exclude:"/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../openjdk/excludes/vendors/eclipse/ProblemList_openjdk17.txt" \ [2025-11-06T06:36:26.521Z] "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../openjdk/openjdk-jdk/test/jdk:jdk_net"; \ [2025-11-06T06:36:26.521Z] if [ $? -eq 0 ]; then echo "-----------------------------------"; echo "jdk_net_1""_PASSED"; echo "-----------------------------------"; cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/..; else echo "-----------------------------------"; echo "jdk_net_1""_FAILED"; echo "-----------------------------------"; fi; \ [2025-11-06T06:36:26.521Z] echo ""; echo "TEST TEARDOWN:"; \ [2025-11-06T06:36:26.521Z] echo "Nothing to be done for teardown."; \ [2025-11-06T06:36:26.521Z] } 2>&1 | tee -a "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/TestTargetResult"; [2025-11-06T06:36:26.521Z] [2025-11-06T06:36:26.521Z] TEST SETUP: [2025-11-06T06:36:26.521Z] Nothing to be done for setup. [2025-11-06T06:36:26.521Z] [2025-11-06T06:36:26.521Z] TESTING: [2025-11-06T06:36:26.521Z] Directory "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1/work" not found: creating [2025-11-06T06:36:26.521Z] Directory "/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/../TKG/output_1762403923729/jdk_net_1/report" not found: creating [2025-11-06T06:36:26.521Z] XML output with verification to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work [2025-11-06T06:44:51.210Z] -------------------------------------------------- [2025-11-06T06:44:51.210Z] TEST: java/net/httpclient/http2/ConnectionFlowControlTest.java [2025-11-06T06:44:51.210Z] TEST JDK: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image [2025-11-06T06:44:51.210Z] [2025-11-06T06:44:51.210Z] ACTION: build -- Passed. All files up to date [2025-11-06T06:44:51.210Z] REASON: User specified action: run build jdk.httpclient.test.lib.http2.Http2TestServer jdk.test.lib.net.SimpleSSLContext [2025-11-06T06:44:51.210Z] TIME: 0.0 seconds [2025-11-06T06:44:51.210Z] messages: [2025-11-06T06:44:51.210Z] command: build jdk.httpclient.test.lib.http2.Http2TestServer jdk.test.lib.net.SimpleSSLContext [2025-11-06T06:44:51.210Z] reason: User specified action: run build jdk.httpclient.test.lib.http2.Http2TestServer jdk.test.lib.net.SimpleSSLContext [2025-11-06T06:44:51.210Z] started: Thu Nov 06 01:44:37 EST 2025 [2025-11-06T06:44:51.210Z] finished: Thu Nov 06 01:44:37 EST 2025 [2025-11-06T06:44:51.210Z] elapsed time (seconds): 0.0 [2025-11-06T06:44:51.210Z] [2025-11-06T06:44:51.210Z] ACTION: build -- Passed. Build successful [2025-11-06T06:44:51.210Z] REASON: Named class compiled on demand [2025-11-06T06:44:51.210Z] TIME: 0.047 seconds [2025-11-06T06:44:51.210Z] messages: [2025-11-06T06:44:51.210Z] command: build ConnectionFlowControlTest [2025-11-06T06:44:51.210Z] reason: Named class compiled on demand [2025-11-06T06:44:51.210Z] started: Thu Nov 06 01:44:37 EST 2025 [2025-11-06T06:44:51.210Z] Test directory: [2025-11-06T06:44:51.210Z] compile: ConnectionFlowControlTest [2025-11-06T06:44:51.210Z] finished: Thu Nov 06 01:44:38 EST 2025 [2025-11-06T06:44:51.210Z] elapsed time (seconds): 0.047 [2025-11-06T06:44:51.210Z] [2025-11-06T06:44:51.210Z] ACTION: compile -- Passed. Compilation successful [2025-11-06T06:44:51.210Z] REASON: .class file out of date or does not exist [2025-11-06T06:44:51.210Z] TIME: 0.047 seconds [2025-11-06T06:44:51.210Z] messages: [2025-11-06T06:44:51.210Z] command: compile /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2/ConnectionFlowControlTest.java [2025-11-06T06:44:51.210Z] reason: .class file out of date or does not exist [2025-11-06T06:44:51.210Z] started: Thu Nov 06 01:44:37 EST 2025 [2025-11-06T06:44:51.210Z] 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 [2025-11-06T06:44:51.210Z] Mode: agentvm [2025-11-06T06:44:51.210Z] Agent id: 1 [2025-11-06T06:44:51.210Z] finished: Thu Nov 06 01:44:38 EST 2025 [2025-11-06T06:44:51.210Z] elapsed time (seconds): 0.047 [2025-11-06T06:44:51.210Z] configuration: [2025-11-06T06:44:51.210Z] Boot Layer (javac runtime environment) [2025-11-06T06:44:51.210Z] class path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/javatest.jar [2025-11-06T06:44:51.210Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/jtreg.jar [2025-11-06T06:44:51.210Z] patch: java.base /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/patches/java.base [2025-11-06T06:44:51.210Z] [2025-11-06T06:44:51.210Z] javac compilation environment [2025-11-06T06:44:51.210Z] add modules: java.base java.net.http java.logging jdk.httpserver [2025-11-06T06:44:51.211Z] add exports: java.base/sun.net ALL-UNNAMED [2025-11-06T06:44:51.211Z] java.base/sun.net.www ALL-UNNAMED [2025-11-06T06:44:51.211Z] java.base/sun.net.www.http ALL-UNNAMED [2025-11-06T06:44:51.211Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2025-11-06T06:44:51.211Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2025-11-06T06:44:51.211Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2025-11-06T06:44:51.211Z] source path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2 [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib [2025-11-06T06:44:51.211Z] class path: /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2 [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar [2025-11-06T06:44:51.211Z] [2025-11-06T06:44:51.211Z] rerun: [2025-11-06T06:44:51.211Z] cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/scratch && \ [2025-11-06T06:44:51.211Z] DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1002/bus \ [2025-11-06T06:44:51.211Z] DISPLAY=:0 \ [2025-11-06T06:44:51.211Z] HOME=/home/jenkins \ [2025-11-06T06:44:51.211Z] LANG=en_US.UTF-8 \ [2025-11-06T06:44:51.211Z] PATH=/bin:/usr/bin:/usr/sbin \ [2025-11-06T06:44:51.211Z] XDG_RUNTIME_DIR=/run/user/1002 \ [2025-11-06T06:44:51.211Z] XDG_SESSION_ID=32070 \ [2025-11-06T06:44:51.211Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image/bin/javac \ [2025-11-06T06:44:51.211Z] -J-ea \ [2025-11-06T06:44:51.211Z] -J-esa \ [2025-11-06T06:44:51.211Z] -J-Xmx512m \ [2025-11-06T06:44:51.211Z] -J-XX:-UseCompressedOops \ [2025-11-06T06:44:51.211Z] -J-Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops' \ [2025-11-06T06:44:51.211Z] -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops' \ [2025-11-06T06:44:51.211Z] -J-Dtest.compiler.opts= \ [2025-11-06T06:44:51.211Z] -J-Dtest.java.opts= \ [2025-11-06T06:44:51.211Z] -J-Dtest.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image \ [2025-11-06T06:44:51.211Z] -J-Dcompile.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image \ [2025-11-06T06:44:51.211Z] -J-Dtest.timeout.factor=8.0 \ [2025-11-06T06:44:51.211Z] -J-Dtest.nativepath=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2025-11-06T06:44:51.211Z] -J-Dtest.root=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2025-11-06T06:44:51.211Z] -J-Dtest.name=java/net/httpclient/http2/ConnectionFlowControlTest.java \ [2025-11-06T06:44:51.211Z] -J-Dtest.file=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2/ConnectionFlowControlTest.java \ [2025-11-06T06:44:51.211Z] -J-Dtest.src=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2 \ [2025-11-06T06:44:51.211Z] -J-Dtest.src.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.211Z] -J-Dtest.classes=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d \ [2025-11-06T06:44:51.211Z] -J-Dtest.class.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.211Z] -J-Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.211Z] -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' \ [2025-11-06T06:44:51.211Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2025-11-06T06:44:51.211Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2025-11-06T06:44:51.211Z] -d /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d \ [2025-11-06T06:44:51.211Z] -sourcepath /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.211Z] -classpath /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2/ConnectionFlowControlTest.java [2025-11-06T06:44:51.211Z] [2025-11-06T06:44:51.211Z] ACTION: testng -- Failed. Execution failed: `main' threw exception: java.lang.Exception: failures: 1 [2025-11-06T06:44:51.211Z] REASON: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.connectionWindowSize=65535 -Djdk.httpclient.windowsize=16384 ConnectionFlowControlTest [2025-11-06T06:44:51.211Z] TIME: 3.8 seconds [2025-11-06T06:44:51.211Z] messages: [2025-11-06T06:44:51.211Z] command: testng -Djdk.internal.httpclient.debug=true -Djdk.httpclient.connectionWindowSize=65535 -Djdk.httpclient.windowsize=16384 ConnectionFlowControlTest [2025-11-06T06:44:51.211Z] reason: User specified action: run testng/othervm -Djdk.internal.httpclient.debug=true -Djdk.httpclient.connectionWindowSize=65535 -Djdk.httpclient.windowsize=16384 ConnectionFlowControlTest [2025-11-06T06:44:51.211Z] started: Thu Nov 06 01:44:38 EST 2025 [2025-11-06T06:44:51.211Z] Mode: othervm [/othervm specified] [2025-11-06T06:44:51.212Z] 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 [2025-11-06T06:44:51.212Z] finished: Thu Nov 06 01:44:41 EST 2025 [2025-11-06T06:44:51.212Z] elapsed time (seconds): 3.8 [2025-11-06T06:44:51.212Z] configuration: [2025-11-06T06:44:51.212Z] Boot Layer [2025-11-06T06:44:51.212Z] add modules: java.base java.net.http java.logging jdk.httpserver [2025-11-06T06:44:51.212Z] add exports: java.base/sun.net ALL-UNNAMED [2025-11-06T06:44:51.212Z] java.base/sun.net.www ALL-UNNAMED [2025-11-06T06:44:51.212Z] java.base/sun.net.www.http ALL-UNNAMED [2025-11-06T06:44:51.212Z] java.net.http/jdk.internal.net.http.common ALL-UNNAMED [2025-11-06T06:44:51.212Z] java.net.http/jdk.internal.net.http.frame ALL-UNNAMED [2025-11-06T06:44:51.212Z] java.net.http/jdk.internal.net.http.hpack ALL-UNNAMED [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] STDOUT: [2025-11-06T06:44:51.212Z] Http2TestServerImpl: start [2025-11-06T06:44:51.212Z] Http2TestServerImpl: start [2025-11-06T06:44:51.212Z] config ConnectionFlowControlTest.setup(): success [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] testing http://127.0.0.1:53765/http2/x [2025-11-06T06:44:51.212Z] connection window: 65535, stream window: 16384, will make 5 requests [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] Sending request:http://127.0.0.1:53765/http2/x?reqId=1 [2025-11-06T06:44:51.212Z] Server localhost/127.0.0.1:53765 received: [2025-11-06T06:44:51.212Z] http://127.0.0.1:53765/http2/x?reqId=1: Hello there! [2025-11-06T06:44:51.212Z] Server: response sent for reqId=1 [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] Sending request:http://127.0.0.1:53765/http2/x?reqId=2 [2025-11-06T06:44:51.212Z] Server localhost/127.0.0.1:53765 received: [2025-11-06T06:44:51.212Z] http://127.0.0.1:53765/http2/x?reqId=2: Hello there! [2025-11-06T06:44:51.212Z] Server: response sent for reqId=2 [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] Sending request:http://127.0.0.1:53765/http2/x?reqId=3 [2025-11-06T06:44:51.212Z] Server localhost/127.0.0.1:53765 received: [2025-11-06T06:44:51.212Z] http://127.0.0.1:53765/http2/x?reqId=3: Hello there! [2025-11-06T06:44:51.212Z] Server: response sent for reqId=3 [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] Sending request:http://127.0.0.1:53765/http2/x?reqId=4 [2025-11-06T06:44:51.212Z] Server localhost/127.0.0.1:53765 received: [2025-11-06T06:44:51.212Z] http://127.0.0.1:53765/http2/x?reqId=4: Hello there! [2025-11-06T06:44:51.212Z] Server: response sent for reqId=4 [2025-11-06T06:44:51.212Z] [2025-11-06T06:44:51.212Z] Sending request:http://127.0.0.1:53765/http2/x?reqId=5 [2025-11-06T06:44:51.212Z] Got EXPECTED: java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.212Z] Exception does not match expectation: java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.212Z] java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:917) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:133) [2025-11-06T06:44:51.212Z] at ConnectionFlowControlTest.test(ConnectionFlowControlTest.java:146) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2025-11-06T06:44:51.212Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2025-11-06T06:44:51.212Z] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) [2025-11-06T06:44:51.212Z] at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) [2025-11-06T06:44:51.212Z] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) [2025-11-06T06:44:51.212Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2025-11-06T06:44:51.212Z] at org.testng.TestRunner.privateRun(TestRunner.java:764) [2025-11-06T06:44:51.212Z] at org.testng.TestRunner.run(TestRunner.java:585) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunner.run(SuiteRunner.java:286) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) [2025-11-06T06:44:51.212Z] at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) [2025-11-06T06:44:51.212Z] at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) [2025-11-06T06:44:51.212Z] at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) [2025-11-06T06:44:51.212Z] at org.testng.TestNG.runSuites(TestNG.java:1069) [2025-11-06T06:44:51.212Z] at org.testng.TestNG.run(TestNG.java:1037) [2025-11-06T06:44:51.212Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) [2025-11-06T06:44:51.212Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2025-11-06T06:44:51.212Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2025-11-06T06:44:51.212Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2025-11-06T06:44:51.212Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2025-11-06T06:44:51.212Z] at java.base/java.lang.Thread.run(Thread.java:840) [2025-11-06T06:44:51.212Z] Caused by: java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Stream.cancel(Stream.java:1410) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Http2Connection.putStream(Http2Connection.java:1432) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Stream.registerStream(Stream.java:1028) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Http2Connection.registerNewStream(Http2Connection.java:1533) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Http2Connection.sendFrame(Http2Connection.java:1557) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Stream.sendHeadersAsync(Stream.java:1000) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$8(Exchange.java:564) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.checkFor407(Exchange.java:435) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(Exchange.java:568) [2025-11-06T06:44:51.212Z] at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) [2025-11-06T06:44:51.212Z] at java.base/java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) [2025-11-06T06:44:51.212Z] at java.base/java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsyncImpl0(Exchange.java:568) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsyncImpl(Exchange.java:411) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsync(Exchange.java:403) [2025-11-06T06:44:51.212Z] at java.net.http/jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:430) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(MultiExchange.java:350) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:174) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.completeAsync(CompletableFuture.java:2673) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.MultiExchange.responseAsync(MultiExchange.java:303) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.sendAsync(HttpClientImpl.java:991) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:878) [2025-11-06T06:44:51.213Z] ... 35 more [2025-11-06T06:44:51.213Z] test ConnectionFlowControlTest.test("http://127.0.0.1:53765/http2/x"): failure [2025-11-06T06:44:51.213Z] java.lang.AssertionError: ProtocolException("protocol error: connection window exceeded") not found [2025-11-06T06:44:51.213Z] at ConnectionFlowControlTest.assertDetailMessage(ConnectionFlowControlTest.java:260) [2025-11-06T06:44:51.213Z] at ConnectionFlowControlTest.test(ConnectionFlowControlTest.java:223) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2025-11-06T06:44:51.213Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2025-11-06T06:44:51.213Z] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) [2025-11-06T06:44:51.213Z] at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) [2025-11-06T06:44:51.213Z] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) [2025-11-06T06:44:51.213Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2025-11-06T06:44:51.213Z] at org.testng.TestRunner.privateRun(TestRunner.java:764) [2025-11-06T06:44:51.213Z] at org.testng.TestRunner.run(TestRunner.java:585) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunner.run(SuiteRunner.java:286) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) [2025-11-06T06:44:51.213Z] at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) [2025-11-06T06:44:51.213Z] at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) [2025-11-06T06:44:51.213Z] at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) [2025-11-06T06:44:51.213Z] at org.testng.TestNG.runSuites(TestNG.java:1069) [2025-11-06T06:44:51.213Z] at org.testng.TestNG.run(TestNG.java:1037) [2025-11-06T06:44:51.213Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) [2025-11-06T06:44:51.213Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2025-11-06T06:44:51.213Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2025-11-06T06:44:51.213Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2025-11-06T06:44:51.213Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2025-11-06T06:44:51.213Z] at java.base/java.lang.Thread.run(Thread.java:840) [2025-11-06T06:44:51.213Z] Caused by: java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:917) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:133) [2025-11-06T06:44:51.213Z] at ConnectionFlowControlTest.test(ConnectionFlowControlTest.java:146) [2025-11-06T06:44:51.213Z] ... 33 more [2025-11-06T06:44:51.213Z] Caused by: java.io.IOException: Stream 9 cancelled [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Stream.cancel(Stream.java:1410) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Http2Connection.putStream(Http2Connection.java:1432) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Stream.registerStream(Stream.java:1028) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Http2Connection.registerNewStream(Http2Connection.java:1533) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Http2Connection.sendFrame(Http2Connection.java:1557) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Stream.sendHeadersAsync(Stream.java:1000) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$8(Exchange.java:564) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.checkFor407(Exchange.java:435) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.lambda$responseAsyncImpl0$9(Exchange.java:568) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:950) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2340) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsyncImpl0(Exchange.java:568) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsyncImpl(Exchange.java:411) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.Exchange.responseAsync(Exchange.java:403) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.MultiExchange.responseAsyncImpl(MultiExchange.java:430) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.MultiExchange.lambda$responseAsync0$2(MultiExchange.java:350) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:174) [2025-11-06T06:44:51.213Z] at java.base/java.util.concurrent.CompletableFuture.completeAsync(CompletableFuture.java:2673) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.MultiExchange.responseAsync(MultiExchange.java:303) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.sendAsync(HttpClientImpl.java:991) [2025-11-06T06:44:51.213Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:878) [2025-11-06T06:44:51.213Z] ... 35 more [2025-11-06T06:44:51.213Z] [2025-11-06T06:44:51.213Z] testing https://127.0.0.1:50855/https2/x [2025-11-06T06:44:51.214Z] connection window: 65535, stream window: 16384, will make 5 requests [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending request:https://127.0.0.1:50855/https2/x?reqId=6 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=6: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=6 [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending request:https://127.0.0.1:50855/https2/x?reqId=7 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=7: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=7 [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending request:https://127.0.0.1:50855/https2/x?reqId=8 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=8: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=8 [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending request:https://127.0.0.1:50855/https2/x?reqId=9 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=9: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=9 [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending request:https://127.0.0.1:50855/https2/x?reqId=10 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=10: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=10 [2025-11-06T06:44:51.214Z] Got EXPECTED: java.net.ProtocolException: protocol error: connection window exceeded [2025-11-06T06:44:51.214Z] Found expected exception: java.net.ProtocolException: protocol error: connection window exceeded [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] Sending last request:https://127.0.0.1:50855/https2/x?reqId=11 [2025-11-06T06:44:51.214Z] Server localhost/127.0.0.1:50855 received: [2025-11-06T06:44:51.214Z] https://127.0.0.1:50855/https2/x?reqId=11: Hello there! [2025-11-06T06:44:51.214Z] Server: response sent for reqId=11 [2025-11-06T06:44:51.214Z] last request reqId=11 sent on different connection as expected: [2025-11-06T06:44:51.214Z] last: localhost/127.0.0.1:50855->/127.0.0.1:51192 [2025-11-06T06:44:51.214Z] previous: localhost/127.0.0.1:50855->/127.0.0.1:51190 [2025-11-06T06:44:51.214Z] test ConnectionFlowControlTest.test("https://127.0.0.1:50855/https2/x"): success [2025-11-06T06:44:51.214Z] Http2TestServerImpl: stop [2025-11-06T06:44:51.214Z] Http2TestServerImpl: stop [2025-11-06T06:44:51.214Z] config ConnectionFlowControlTest.teardown(): success [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] =============================================== [2025-11-06T06:44:51.214Z] java/net/httpclient/http2/ConnectionFlowControlTest.java [2025-11-06T06:44:51.214Z] Total tests run: 2, Passes: 1, Failures: 1, Skips: 0 [2025-11-06T06:44:51.214Z] =============================================== [2025-11-06T06:44:51.214Z] [2025-11-06T06:44:51.214Z] STDERR: [2025-11-06T06:44:51.214Z] TestServer(1): accepting connections [2025-11-06T06:44:51.214Z] TestServer(2): accepting connections [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [7ms] HttpClientImpl(1) proxySelector is sun.net.spi.DefaultProxySelector@612f669 (user-supplied=false) [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [16ms] HttpClientImpl(1) ClientImpl (async) send http://127.0.0.1:53765/http2/x?reqId=1 POST [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [31ms] Exchange establishing exchange for http://127.0.0.1:53765/http2/x?reqId=1 POST, [2025-11-06T06:44:51.214Z] proxy=null [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [43ms] Http2ClientImpl not found in connection pool [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [43ms] ExchangeImpl get: Trying to get HTTP/2 connection [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [43ms] ExchangeImpl handling HTTP/2 connection creation result [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [43ms] ExchangeImpl new Http1Exchange, try to upgrade [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [53ms] PlainHttpConnection(?) Initial receive buffer size is: 43690 [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [53ms] PlainHttpConnection(?) Initial send buffer size is: 8192 [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [62ms] Exchange checkFor407: all clear [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [62ms] Http1Exchange Sending headers only [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [66ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@6543dbac queue.isEmpty: true [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [74ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@6543dbac, demand=1, canRequestMore=true, queue.isEmpty=true [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [74ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [78ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [78ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [78ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [78ms] Http1Exchange response created in advance [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [78ms] Http1Exchange initiating connect async [2025-11-06T06:44:51.214Z] DEBUG: [MainThread] [80ms] PlainHttpConnection(SocketTube(1)) registering connect event [2025-11-06T06:44:51.214Z] TestServer(1): connection accepted [2025-11-06T06:44:51.214Z] DEBUG: [HttpClient-1-SelectorManager] [84ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@69683a81 for 8 (true) [2025-11-06T06:44:51.214Z] DEBUG: [HttpClient-1-SelectorManager] [88ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: finishing connect [2025-11-06T06:44:51.214Z] DEBUG: [HttpClient-1-SelectorManager] [89ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: connect finished: true, cancelled: false, Local addr: /127.0.0.1:34136 [2025-11-06T06:44:51.214Z] TestServer(1): stopping is: false [2025-11-06T06:44:51.214Z] TestServer(1): accepting connections [2025-11-06T06:44:51.214Z] TestServer(1): creating connection [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [101ms] PlainHttpConnection(SocketTube(1)) finishConnect, setting connected=true [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [102ms] Http1Exchange SocketTube(1) connecting flows [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [102ms] SocketTube(1) connecting flows [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [103ms] SocketTube(1) read publisher got subscriber [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [103ms] SocketTube(1) registering subscribe event [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [103ms] SocketTube(1) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0] [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [104ms] Http1Publisher(SocketTube(1)) got subscriber: SocketTube(1) [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [104ms] SocketTube(1) subscribed for writing [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [105ms] SocketTube(1) write: registering startSubscription event [2025-11-06T06:44:51.214Z] DEBUG: [pool-1-thread-1] [105ms] Http1Exchange requestAction.headers [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [110ms] Http1Exchange setting outgoing with headers [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [111ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=237 cap=237]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [111ms] Http1Publisher(SocketTube(1)) WriteTask [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [115ms] Http1Publisher(SocketTube(1)) hasOutgoing = true, demand = 0 [2025-11-06T06:44:51.215Z] TestServer(1): New connection from Socket[addr=/127.0.0.1,port=34136,localport=53765] [2025-11-06T06:44:51.215Z] TestServer(1): starting connection [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [120ms] SocketTube(1) subscribe event raised [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [120ms] SocketTube(1) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@770a0529 [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [120ms] SocketTube(1) read demand reset to 0 [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [121ms] SocketTube(1) calling onSubscribe [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [121ms] Http1AsyncReceiver(SocketTube(1)) Received onSubscribed from upstream [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [121ms] SocketTube(1) onSubscribe called [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [121ms] SocketTube(1) pending subscriber subscribed [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [121ms] SocketTube(1) write: starting subscription [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [122ms] SocketTube(1) write: offloading requestMore [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [122ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [123ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [123ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: requesting one more from upstream [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [123ms] SocketTube(1) got some demand for reading [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [123ms] SocketTube(1) resuming read event [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-1] [124ms] SocketTube(1) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0] [2025-11-06T06:44:51.215Z] DEBUG: [HttpClient-1-SelectorManager] [129ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 1 (true) [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Http1Publisher(SocketTube(1)) WriteTask [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Http1Publisher(SocketTube(1)) hasOutgoing = true, demand = 1 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Http1Exchange initiating completion of headersSentCF [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Exchange checkFor407: all clear [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Exchange sendRequestBody [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [129ms] Http1Exchange sendBodyAsync [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] Http1Exchange bodySubscriber is class jdk.internal.net.http.Http1Request$FixedContentSubscriber [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] Http1Exchange requesting more request body from the subscriber [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] jdk.internal.net.http.Http1Request@69f2f3f0 Http1BodySubscriber requesting 1, from jdk.internal.net.http.PullPublisher$Subscription@6393167d [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] jdk.internal.net.http.Http1Request@69f2f3f0 onNext [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=12 cap=12]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] jdk.internal.net.http.Http1Request@69f2f3f0 onComplete [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [130ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [131ms] Http1Publisher(SocketTube(1)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=237 cap=237]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [131ms] Http1Publisher(SocketTube(1)) onNext with 237 bytes [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [131ms] SocketTube(1) trying to write: 237 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [131ms] SocketTube(1) wrote: 237 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [131ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Exchange requesting more request body from the subscriber [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] jdk.internal.net.http.Http1Request@69f2f3f0 Http1BodySubscriber requesting 1, from jdk.internal.net.http.PullPublisher$Subscription@6393167d [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Publisher(SocketTube(1)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=12 cap=12]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Publisher(SocketTube(1)) onNext with 12 bytes [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) trying to write: 12 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) wrote: 12 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1 [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Exchange initiating completion of bodySentCF [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Exchange sendBodyAsync completed successfully [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [132ms] Http1Exchange reading headers [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [134ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: (remaining: 0) READING_HEADERS [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [134ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) First time around [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [134ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) headersReader is not yet completed [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [134ms] Http1Publisher(SocketTube(1)) outgoing: DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null] [2025-11-06T06:44:51.215Z] DEBUG: [pool-1-thread-2] [134ms] Http1Publisher(SocketTube(1)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@c7e7059 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [134ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [136ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 0 (false) [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [137ms] SocketTube(1) read bytes: 71 [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [137ms] Http1AsyncReceiver(SocketTube(1)) Putting 71 bytes into the queue [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [137ms] SocketTube(1) resuming read event [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [138ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 1 (false) [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [138ms] SocketTube(1) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [138ms] Http1AsyncReceiver(SocketTube(1)) Got 71 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@6543dbac [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [138ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [138ms] Http1AsyncReceiver(SocketTube(1)) Forwarding 71 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@6543dbac [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [139ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Sending 71/71 bytes to header parser [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [140ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Parsing headers completed. bytes=71 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [140ms] Http1AsyncReceiver(SocketTube(1)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@6543dbac [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [140ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: creating Response object; state is now READING_BODY [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [140ms] Http1Exchange getResponseAsync completed successfully [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [140ms] Exchange Upgrading async PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:34136 remote=/127.0.0.1:53765] [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [141ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) readBody: return2Cache: false [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [161ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@12ede6fe(1) [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [162ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@14094870/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@236c211c queue.isEmpty: false [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] Http1AsyncReceiver(SocketTube(1)) Delegate done: 0 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] PlainHttpConnection(SocketTube(1))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Exchange$Http1ResponseBodySubscriber [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] HttpClientImpl(1) body subscriber registered: 1 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] Http1AsyncReceiver(SocketTube(1)) cleared [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] HttpClientImpl(1) body subscriber unregistered: 0 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [165ms] Exchange Ignored body [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [178ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 0) maxFrameSize=16384, initWindowSize=65535, limit=32768 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: ?) maxFrameSize=16384, initWindowSize=16384, limit=0 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] Http2Connection(SocketTube(1)) Opened stream 1 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] Http2Connection(SocketTube(1))/Stream(1) Stream 1 registered (cancelled: false, registerIfCancelled: true) [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] Http2Connection(SocketTube(1))/Stream(1) requestSent: streamid=1 but response not received [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) connecting flows [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) read publisher got subscriber [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) registering subscribe event [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) leaving read.subscribe: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) subscribed for writing [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) write: resetting demand to 0 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [181ms] SocketTube(1) write: registering startSubscription event [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [182ms] PlainHttpConnection(SocketTube(1)) added 69 bytes in the priority write queue [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [182ms] PlainHttpConnection(SocketTube(1)) signalling the publisher of the write queue [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-2] [182ms] Http2Connection(SocketTube(1)) Triggering processing of buffered data after sending connection preface [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [183ms] SocketTube(1) subscribe event raised [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [183ms] SocketTube(1) handling pending subscription for jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@515ac85a [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: dropSubscription [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] SocketTube(1) read demand reset to 0 [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] SocketTube(1) calling onSubscribe [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] Http2Connection(SocketTube(1)) onSubscribe: requesting Long.MAX_VALUE for reading [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] SocketTube(1) got some demand for reading [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [184ms] SocketTube(1) resuming read event [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [185ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 1 (false) [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [185ms] SocketTube(1) leaving request(9223372036854775807): Reading: [ops=1, demand=9223372036854775807, stopped=false], Writing: [ops=0, demand=0] [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [185ms] SocketTube(1) onSubscribe called [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [185ms] SocketTube(1) pending subscriber subscribed [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [186ms] SocketTube(1) write: starting subscription [2025-11-06T06:44:51.216Z] DEBUG: [HttpClient-1-SelectorManager] [186ms] SocketTube(1) write: offloading requestMore [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [186ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [187ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1) [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [195ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: sending 69 bytes (1 buffers) to SocketTube(1) [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [196ms] SocketTube(1) trying to write: 69 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [196ms] SocketTube(1) wrote: 69 [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [197ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [197ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1) [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [197ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=9223372036854775807, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [197ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=9223372036854775807, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.216Z] DEBUG: [pool-1-thread-1] [197ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=9223372036854775807, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [199ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [199ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [199ms] FramesDecoder Not enough data to parse frame body, needs: 36, has: 0 [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [200ms] FramesDecoder decodes: 36 [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [200ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.217Z] DEBUG: [TestServer(1)-pool] [200ms] FramesDecoder Got frame: SETTINGS: length=36, streamid=0, flags=0 Settings: HEADER_TABLE_SIZE=16384 ENABLE_PUSH=0 MAX_CONCURRENT_STREAMS=0 INITIAL_WINDOW_SIZE=16384 MAX_FRAME_SIZE=16384 MAX_HEADER_LIST_SIZE=393216 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [206ms] Http2Connection(SocketTube(1)) onNext: got 0 bytes in 1 buffers [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [206ms] Http2Connection(SocketTube(1)) sending 0 to Http2Connection.asyncReceive [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [206ms] Http1AsyncReceiver(SocketTube(1)) stopping [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [206ms] Http1Exchange asyncReceiver finished (failed=null) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [206ms] Http1AsyncReceiver(SocketTube(1)) Flushing 0 bytes from queue into initial buffer (remaining=0, free=0) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [208ms] Http1AsyncReceiver(SocketTube(1)) Initial buffer now has 0 pos=0 limit=0 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [208ms] Http2Connection(SocketTube(1)) H2 Received EMPTY_TRIGGER [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [208ms] Http2Connection(SocketTube(1)) H2 processed buffered data [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [208ms] Http2ClientImpl offering to the connection pool: Http2Connection(SocketTube(1)) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [208ms] Http2ClientImpl put in the connection pool: Http2Connection(SocketTube(1)) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1AsyncReceiver(SocketTube(1)) cleared [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Exchange Getting response async streamid: 1 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Finished reading body: READING_BODY [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@12ede6fe(1) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@14094870/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@236c211c, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=true [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 9223372036854775807 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=false, hasDemand=true [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [209ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: no need to request more [2025-11-06T06:44:51.217Z] TestServer(1): POST /http2/x?reqId=1 [2025-11-06T06:44:51.217Z] TestServer(1): creating input stream for stream 1 [2025-11-06T06:44:51.217Z] TestServer(1): Using handler for: /http2/ [2025-11-06T06:44:51.217Z] Sent response headers 200 [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [259ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [259ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.217Z] TestServer(1): connection started [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [260ms] FramesDecoder Not enough data to parse frame body, needs: 36, has: 0 [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [260ms] FramesDecoder decodes: 36 [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [260ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.217Z] DEBUG: [readLoop] [260ms] FramesDecoder Got frame: SETTINGS: length=36, streamid=0, flags=0 Settings: HEADER_TABLE_SIZE=16384 ENABLE_PUSH=0 MAX_CONCURRENT_STREAMS=0 INITIAL_WINDOW_SIZE=16384 MAX_FRAME_SIZE=16384 MAX_HEADER_LIST_SIZE=393216 [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [279ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 0 (false) [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [279ms] SocketTube(1) read bytes: 1931 [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [280ms] Http2Connection(SocketTube(1)) onNext: got 1931 bytes in 1 buffers [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [280ms] SocketTube(1) resuming read event [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [280ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 1 (false) [2025-11-06T06:44:51.217Z] DEBUG: [HttpClient-1-SelectorManager] [280ms] SocketTube(1) leaving read() loop after onNext: Reading: [ops=1, demand=9223372036854775806, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] Http2Connection(SocketTube(1)) sending 1931 to Http2Connection.asyncReceive [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] Http2Connection(SocketTube(1)) H2 Receiving(1): 1931 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] Http2Connection(SocketTube(1)) Processing 1931 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder decodes: 1931 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder Got frame: SETTINGS: length=30, streamid=0, flags=0 Settings: HEADER_TABLE_SIZE=4096 ENABLE_PUSH=1 MAX_CONCURRENT_STREAMS=2147483647 INITIAL_WINDOW_SIZE=65535 MAX_FRAME_SIZE=16384 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] PlainHttpConnection(SocketTube(1)) added 9 bytes to the write queue [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] PlainHttpConnection(SocketTube(1)) signalling the publisher of the write queue [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: sending 9 bytes (1 buffers) to SocketTube(1) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] SocketTube(1) trying to write: 9 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] SocketTube(1) wrote: 9 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=9223372036854775806, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=9223372036854775806, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] Http2Connection(SocketTube(1))/Stream(1) incoming: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] WindowController Stream 1 window size is now 65547 (amount added 12) [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=0, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.217Z] DEBUG: [pool-1-thread-2] [295ms] WindowController Connection window size is now 65547 (amount added 12) [2025-11-06T06:44:51.219Z] DEBUG: [pool-1-thread-2] [295ms] FramesDecoder Got frame: HEADERS: length=51, streamid=1, flags=END_HEADERS [2025-11-06T06:44:51.219Z] DEBUG: [pool-1-thread-2] [296ms] Http2Connection(SocketTube(1))/Stream(1) incoming: HEADERS: length=51, streamid=1, flags=END_HEADERS [2025-11-06T06:44:51.219Z] DEBUG: [pool-1-thread-2] [296ms] Http2Connection(SocketTube(1))/Stream(1) Response builder cleared, ready to receive new headers. [2025-11-06T06:44:51.219Z] DEBUG: [pool-1-thread-2] [296ms] Http2Connection(SocketTube(1))/Stream(1) Completing responseCF(0) with response headers [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [296ms] Http2Connection(SocketTube(1))/Stream(1) Getting BodySubscriber for: (POST http://127.0.0.1:53765/http2/x?reqId=1) 200 HTTP_2 Local port: 34136 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [297ms] Http2Connection(SocketTube(1))/Stream(1) subscribing user subscriber [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [298ms] HttpClientImpl(1) body subscriber registered: 1 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [298ms] HttpResponseInputStream onSubscribe called [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [298ms] HttpResponseInputStream onSubscribe: requesting 1 [2025-11-06T06:44:51.220Z] DEBUG: [readLoop] [299ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.220Z] DEBUG: [readLoop] [299ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.220Z] DEBUG: [readLoop] [299ms] FramesDecoder Got frame: SETTINGS: length=0, streamid=0, flags=ACK Settings: [2025-11-06T06:44:51.220Z] DEBUG: [readLoop] [299ms] FramesDecoder decodes: 0 [2025-11-06T06:44:51.220Z] DEBUG: [readLoop] [299ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [319ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 0 (false) [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [319ms] SocketTube(1) read bytes: 2352 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [319ms] HttpClientImpl(1) ClientImpl (async) elapsed 282 millis for POST to http://127.0.0.1:53765/http2/x?reqId=1 [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [319ms] Http2Connection(SocketTube(1)) onNext: got 2352 bytes in 1 buffers [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [320ms] SocketTube(1) resuming read event [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] Http2Connection(SocketTube(1))/Stream(1) incoming: onNext(12) [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] HttpResponseInputStream next item received [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] HttpResponseInputStream item offered [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 0) update: 12, received: 12, limit: 32768 [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [320ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@3c7fc3ce for 1 (false) [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 1) update: 12, received: 12, limit: 0 [2025-11-06T06:44:51.220Z] DEBUG: [HttpClient-1-SelectorManager] [320ms] SocketTube(1) leaving read() loop after onNext: Reading: [ops=1, demand=9223372036854775805, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [320ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 1) sending window update: 12 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] PlainHttpConnection(SocketTube(1)) added 13 bytes in the priority write queue [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] PlainHttpConnection(SocketTube(1)) signalling the publisher of the write queue [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: sending 13 bytes (1 buffers) to SocketTube(1) [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] SocketTube(1) trying to write: 13 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] SocketTube(1) wrote: 13 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] SocketTube(1) write: requesting more... [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1) [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] SocketTube(1) leaving requestMore: Reading: [ops=1, demand=9223372036854775805, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=9223372036854775805, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [324ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [325ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.220Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube(1))/Stream(1) incoming: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.221Z] DEBUG: [pool-1-thread-2] [326ms] FramesDecoder Got frame: DATA: length=12, streamid=1, flags=0 [2025-11-06T06:44:51.221Z] DEBUG: [pool-1-thread-2] [326ms] Http2Connection(SocketTube [2025-11-06T06:44:51.221Z] [2025-11-06T06:44:51.221Z] ... [2025-11-06T06:44:51.221Z] Output overflow: [2025-11-06T06:44:51.221Z] JT Harness has limited the test output to the text [2025-11-06T06:44:51.221Z] at the beginning and the end, so that you can see how the [2025-11-06T06:44:51.221Z] test began, and how it completed. [2025-11-06T06:44:51.221Z] [2025-11-06T06:44:51.221Z] If you need to see more of the output from the test, [2025-11-06T06:44:51.221Z] set the system property javatest.maxOutputSize to a higher [2025-11-06T06:44:51.221Z] value. The current value is 100000 [2025-11-06T06:44:51.221Z] ... [2025-11-06T06:44:51.221Z] [2025-11-06T06:44:51.221Z] dLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 976ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] TestServer(1): stopping 1 connections [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.221Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.222Z] TestServer(2): stopping 2 connections [2025-11-06T06:44:51.222Z] TestServer(2): Server connection to /127.0.0.1:51192 stopping. 1 streams [2025-11-06T06:44:51.222Z] TestServer(2): Sending GOAWAY frame GOAWAY: length=8, streamid=0, flags=0 Error: Not an error lastStreamId=1, Debugdata: from server connection jdk.httpclient.test.lib.http2.Http2TestServerConnection@4e0de18c [2025-11-06T06:44:51.222Z] TestServer(2): Connection writer stopping localhost/127.0.0.1:50855->/127.0.0.1:51192 [2025-11-06T06:44:51.222Z] TestServer(1): finished [2025-11-06T06:44:51.222Z] TestServer(2): finished [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@7e1a26df for 0 (false) [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] SocketTube(3) read bytes: 80 [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] SSL Reader(SocketTube(3)) onNext [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] SSL Reader(SocketTube(3)) Adding 80 bytes to read buffer [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] HttpClientImpl(2) aborting selector manager(closed=false): java.util.concurrent.RejectedExecutionException: Task jdk.internal.net.http.common.SequentialScheduler$SchedulableTask@4e2c3d4a rejected from java.util.concurrent.ThreadPoolExecutor@612fc68e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 25] [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 979ms] HttpClientImpl(2) aborting pending requests due to: class java.util.concurrent.RejectedExecutionException [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 977ms] FramesDecoder decodes: 9 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 980ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 980ms] FramesDecoder Not enough data to parse frame body, needs: 4, has: 0 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 980ms] FramesDecoder decodes: 4 [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 980ms] FramesDecoder Tail size is now: 0, current= [2025-11-06T06:44:51.222Z] DEBUG: [readLoop] [2s 980ms] FramesDecoder Got frame: WINDOW_UPDATE: length=4, streamid=1, flags=0 WindowUpdate: 12 [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SocketTube(3) resuming read event [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@7e1a26df for 1 (false) [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SocketTube(3) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] HttpClientImpl(2) SelectorManager shutting down [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] Http2ClientImpl stopping [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] Http2Connection(SSLTube(SocketTube(3))) Close all streams [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] AsyncSSLConnection(SSLTube(SocketTube(3))) added 34 bytes to the write queue [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] AsyncSSLConnection(SSLTube(SocketTube(3))) signalling the publisher of the write queue [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] AsyncSSLConnection(SSLTube(SocketTube(3))) HttpPublisher: sending 34 bytes (1 buffers) to SSLTube(SocketTube(3)) [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSLTube(SocketTube(3)) sending 1 buffers to SSL flow delegate [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) onNext [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) added 1 (34 bytes) to the writeList [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) processData, writeList remaining:34, hsTriggered:false, needWrap:false [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) wrapping 34 bytes [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) SSLResult: Status = OK HandshakeStatus = NOT_HANDSHAKING [2025-11-06T06:44:51.222Z] bytesConsumed = 34 bytesProduced = 72 sequenceNumber = 1368 [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) OK => produced: 72 bytes into 72, not wrapped: 0 [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) wrapBuffer returned Status = OK HandshakeStatus = NOT_HANDSHAKING [2025-11-06T06:44:51.222Z] bytesConsumed = 34 bytesProduced = 72 sequenceNumber = 1368 [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) Sending 72 bytes downstream [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) Adding 72 to outputQ queue [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) pushScheduler is alive [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) DownstreamPusher: queue not empty, downstreamSubscription: SubscriptionBase: window = 1 cancelled = false [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SSL Writer(SocketTube(3)) DownstreamPusher: Pushing 72 bytes downstream [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SocketTube(3) write error: java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SocketTube(3) error signalled java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 986ms] SocketTube(3) pausing read event [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 987ms] SocketTube(3) Sending error java.io.IOException: selector manager closed to subscriber READER: SubscriberWrapper: upstreamCompleted: false upstreamWindow: 0 downstreamCompleted: false completionAcknowledged: false outputQ size: 0 cf: jdk.internal.net.http.common.MinimalFuture@575a4e02[Not completed, 4 dependents] (id=459) downstreamSubscription: SubscriptionBase: window = 9223372036854774436 cancelled = false downstreamSubscriber: SSLSubscriberWrapper[SSLTube(SocketTube(3)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@4e797afe, getALPN: jdk.internal.net.http.common.MinimalFuture@608a62c0[Completed normally] (id=465), onCompleteReceived: false, onError: null], readBuf: java.nio.HeapByteBuffer[pos=0 lim=80 cap=65536], count: 28811, scheduler: running, status: OK, handshakeState: 0, engine: NOT_HANDSHAKING [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 987ms] SocketTube(3) forwarding error to subscriber: java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 987ms] SSL Reader(SocketTube(3)) onError: java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] DEBUG: [HttpClient-2-SelectorManager] [2s 987ms] SSL Reader(SocketTube(3)) error java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] java.io.IOException: selector manager closed [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.selectorClosedException(HttpClientImpl.java:1073) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.selectorClosedException(HttpClientImpl.java:851) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalWriteSubscriber.tryFlushCurrent(SocketTube.java:345) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalWriteSubscriber.onNext(SocketTube.java:317) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.SocketTube.onNext(SocketTube.java:135) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.SocketTube.onNext(SocketTube.java:58) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run1(SubscriberWrapper.java:316) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run(SubscriberWrapper.java:259) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:232) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:198) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.sendResultBytes(SSLFlowDelegate.java:949) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.processData(SSLFlowDelegate.java:832) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer$WriterDownstreamPusher.run(SSLFlowDelegate.java:708) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.222Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.incoming(SSLFlowDelegate.java:732) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.incomingCaller(SubscriberWrapper.java:438) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:379) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:57) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLTube.onNext(SSLTube.java:664) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLTube.onNext(SSLTube.java:68) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher$HttpWriteSubscription.flush(HttpConnection.java:519) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.flushTask(HttpConnection.java:473) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.signal(HttpConnection.java:480) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.signalEnqueued(HttpConnection.java:542) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.Http2Connection.sendFrame(Http2Connection.java:1568) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.Http2Connection.close(Http2Connection.java:722) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:231) [2025-11-06T06:44:51.223Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:223) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:528) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:1177) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1376) [2025-11-06T06:44:51.223Z] Caused by: java.util.concurrent.RejectedExecutionException: Task jdk.internal.net.http.common.SequentialScheduler$SchedulableTask@4e2c3d4a rejected from java.util.concurrent.ThreadPoolExecutor@612fc68e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 25] [2025-11-06T06:44:51.223Z] at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) [2025-11-06T06:44:51.223Z] at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) [2025-11-06T06:44:51.223Z] at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.ensureExecutedAsync(HttpClientImpl.java:180) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:172) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:305) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:274) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader.incoming(SSLFlowDelegate.java:316) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.incomingCaller(SubscriberWrapper.java:438) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:379) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:57) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:865) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:782) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:965) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:253) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:1402) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:1347) [2025-11-06T06:44:51.223Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1347) [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 989ms] SSL Reader(SocketTube(3)) DownstreamPusher: forwarding error downstream: java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 990ms] SSLTube(SocketTube(3)) SSLSubscriberWrapper[SSLTube(SocketTube(3)), delegate: DelegateWrapper[subscribedCalled: true, subscribedDone: true, completed: false, error: null]: jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@4e797afe, getALPN: jdk.internal.net.http.common.MinimalFuture@608a62c0[Completed normally] (id=465), onCompleteReceived: false, onError: java.io.IOException: selector manager closed]: onErrorImpl: java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 990ms] Http2Connection(SSLTube(SocketTube(3))) onError: java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 990ms] HttpClientImpl(2) aborting selector manager(closed=true): java.util.concurrent.RejectedExecutionException: Task jdk.internal.net.http.common.SequentialScheduler$SchedulableTask@6028e282 rejected from java.util.concurrent.ThreadPoolExecutor@612fc68e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 25] [2025-11-06T06:44:51.223Z] DEBUG: [Thread-13] [2s 991ms] SSL Reader(SocketTube(3)) processData: readBuf remaining:80, state: NOT_HANDSHAKING , engine handshake status:NOT_HANDSHAKING [2025-11-06T06:44:51.223Z] DEBUG: [Thread-13] [2s 991ms] SSL Reader(SocketTube(3)) Unwrapping: 80 [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 991ms] SSLTube(SocketTube(3)) subscriber completed with error: java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 991ms] AsyncSSLConnection(SSLTube(SocketTube(3))) HttpPublisher: cancelled by SSLTube(SocketTube(3)) [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 991ms] SSL Reader(SocketTube(3)) stop [2025-11-06T06:44:51.223Z] DEBUG: [HttpClient-2-SelectorManager] [2s 991ms] SSL Writer(SocketTube(3)) stop [2025-11-06T06:44:51.223Z] DEBUG: [Thread-14] [2s 991ms] Http2Connection(SSLTube(SocketTube(3))) Stopping scheduler java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] java.io.IOException: selector manager closed [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.selectorClosedException(HttpClientImpl.java:1073) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.selectorClosedException(HttpClientImpl.java:851) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalWriteSubscriber.tryFlushCurrent(SocketTube.java:345) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalWriteSubscriber.onNext(SocketTube.java:317) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube.onNext(SocketTube.java:135) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.SocketTube.onNext(SocketTube.java:58) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run1(SubscriberWrapper.java:316) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run(SubscriberWrapper.java:259) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:232) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:198) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.sendResultBytes(SSLFlowDelegate.java:949) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.processData(SSLFlowDelegate.java:832) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer$WriterDownstreamPusher.run(SSLFlowDelegate.java:708) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Writer.incoming(SSLFlowDelegate.java:732) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.incomingCaller(SubscriberWrapper.java:438) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:379) [2025-11-06T06:44:51.223Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:57) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SSLTube.onNext(SSLTube.java:664) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SSLTube.onNext(SSLTube.java:68) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher$HttpWriteSubscription.flush(HttpConnection.java:519) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.flushTask(HttpConnection.java:473) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.signal(HttpConnection.java:480) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpConnection$PlainHttpPublisher.signalEnqueued(HttpConnection.java:542) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.Http2Connection.sendFrame(Http2Connection.java:1568) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.Http2Connection.close(Http2Connection.java:722) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.close(Http2ClientImpl.java:231) [2025-11-06T06:44:51.224Z] at java.base/java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.Http2ClientImpl.stop(Http2ClientImpl.java:223) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl.stop(HttpClientImpl.java:528) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.shutdown(HttpClientImpl.java:1177) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1376) [2025-11-06T06:44:51.224Z] Caused by: java.util.concurrent.RejectedExecutionException: Task jdk.internal.net.http.common.SequentialScheduler$SchedulableTask@4e2c3d4a rejected from java.util.concurrent.ThreadPoolExecutor@612fc68e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 25] [2025-11-06T06:44:51.224Z] at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2065) [2025-11-06T06:44:51.224Z] at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:833) [2025-11-06T06:44:51.224Z] at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1365) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.ensureExecutedAsync(HttpClientImpl.java:180) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:172) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:305) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:274) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader.incoming(SSLFlowDelegate.java:316) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.incomingCaller(SubscriberWrapper.java:438) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:379) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.onNext(SubscriberWrapper.java:57) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:865) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:782) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:965) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:253) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:1402) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:1347) [2025-11-06T06:44:51.224Z] at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) [2025-11-06T06:44:51.224Z] at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:1347) [2025-11-06T06:44:51.224Z] DEBUG: [Thread-14] [2s 993ms] Http2Connection(SSLTube(SocketTube(3))) Shutting down h2c (state=half-closed-local): java.io.IOException: selector manager closed [2025-11-06T06:44:51.224Z] DEBUG: [Thread-14] [2s 993ms] Http2ClientImpl removing from the connection pool: Http2Connection(SSLTube(SocketTube(3))) [2025-11-06T06:44:51.224Z] DEBUG: [Thread-14] [2s 993ms] Http2ClientImpl removed from the connection pool: Http2Connection(SSLTube(SocketTube(3))) [2025-11-06T06:44:51.224Z] DEBUG: [Thread-14] [2s 993ms] PlainHttpConnection(SocketTube(3)) Closing channel: channel not registered with selector [2025-11-06T06:44:51.224Z] DEBUG: [Thread-14] [2s 993ms] SocketTube(3) signal read error: java.io.IOException: connection closed locally [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 17ms] SSL Reader(SocketTube(3)) Decoded 0 bytes out of 80 into buffer of 64 remaining to decode: 40 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 17ms] SSL Reader(SocketTube(3)) Unwrapped: result: Status = OK HandshakeStatus = NOT_HANDSHAKING [2025-11-06T06:44:51.224Z] bytesConsumed = 40 bytesProduced = 0 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 17ms] SSL Reader(SocketTube(3)) Unwrapped: consumed: 40 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 17ms] SSL Reader(SocketTube(3)) Unwrapping: 40 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSLFlowDelegate(SocketTube(3)) doClosure(Status = CLOSED HandshakeStatus = NEED_WRAP [2025-11-06T06:44:51.224Z] bytesConsumed = 40 bytesProduced = 0): NEED_WRAP [isOutboundDone: false, isInboundDone: true] [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSLFlowDelegate(SocketTube(3)) doClosure: close_notify received [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSL Reader(SocketTube(3)) Unwrapped: result: Status = CLOSED HandshakeStatus = NEED_WRAP [2025-11-06T06:44:51.224Z] bytesConsumed = 40 bytesProduced = 0 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSL Reader(SocketTube(3)) Unwrapped: consumed: 40 [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSL Reader(SocketTube(3)) completing [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSL Reader(SocketTube(3)) completionAcknowledged upstreamCompleted:true, downstreamCompleted:true, closing:false [2025-11-06T06:44:51.224Z] DEBUG: [Thread-13] [3s 18ms] SSL Reader(SocketTube(3)) pushScheduler is stopped! [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) Stopping read scheduler [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) leaving read() loop with error: Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=1] [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) Read scheduler stopped [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) write: cancel [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) write: resetting demand to 0 [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] AsyncSSLConnection(SSLTube(SocketTube(3))) HttpPublisher: cancelled by SSLTube(SocketTube(3)) [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] SocketTube(3) leaving w.onNext Reading: [ops=0, demand=0, stopped=true], Writing: [ops=0, demand=0] [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] Http2Connection(SSLTube(SocketTube(3))) Shutting down h2c (state=shutdown+half-closed-local): java.io.EOFException: HTTP/2 client stopped [2025-11-06T06:44:51.224Z] DEBUG: [HttpClient-2-SelectorManager] [3s 18ms] Http2Connection(SSLTube(SocketTube(3))) Close all streams [2025-11-06T06:44:51.224Z] java.lang.Exception: failures: 1 [2025-11-06T06:44:51.224Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:104) [2025-11-06T06:44:51.224Z] at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:58) [2025-11-06T06:44:51.224Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2025-11-06T06:44:51.224Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) [2025-11-06T06:44:51.224Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2025-11-06T06:44:51.224Z] at java.base/java.lang.reflect.Method.invoke(Method.java:569) [2025-11-06T06:44:51.224Z] at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) [2025-11-06T06:44:51.224Z] at java.base/java.lang.Thread.run(Thread.java:840) [2025-11-06T06:44:51.224Z] [2025-11-06T06:44:51.224Z] JavaTest Message: Test threw exception: java.lang.Exception: failures: 1 [2025-11-06T06:44:51.224Z] JavaTest Message: shutting down test [2025-11-06T06:44:51.224Z] [2025-11-06T06:44:51.224Z] STATUS:Failed.`main' threw exception: java.lang.Exception: failures: 1 [2025-11-06T06:44:51.224Z] rerun: [2025-11-06T06:44:51.224Z] cd /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/scratch && \ [2025-11-06T06:44:51.224Z] DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1002/bus \ [2025-11-06T06:44:51.224Z] DISPLAY=:0 \ [2025-11-06T06:44:51.224Z] HOME=/home/jenkins \ [2025-11-06T06:44:51.224Z] LANG=en_US.UTF-8 \ [2025-11-06T06:44:51.224Z] PATH=/bin:/usr/bin:/usr/sbin \ [2025-11-06T06:44:51.224Z] XDG_RUNTIME_DIR=/run/user/1002 \ [2025-11-06T06:44:51.224Z] XDG_SESSION_ID=32070 \ [2025-11-06T06:44:51.225Z] CLASSPATH=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/javatest.jar:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jvmtest/openjdk/jtreg/lib/jtreg.jar \ [2025-11-06T06:44:51.225Z] /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image/bin/java \ [2025-11-06T06:44:51.225Z] -Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops' \ [2025-11-06T06:44:51.225Z] -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops' \ [2025-11-06T06:44:51.225Z] -Dtest.compiler.opts= \ [2025-11-06T06:44:51.225Z] -Dtest.java.opts= \ [2025-11-06T06:44:51.225Z] -Dtest.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image \ [2025-11-06T06:44:51.225Z] -Dcompile.jdk=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/j2sdk-image \ [2025-11-06T06:44:51.225Z] -Dtest.timeout.factor=8.0 \ [2025-11-06T06:44:51.225Z] -Dtest.nativepath=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2025-11-06T06:44:51.225Z] -Dtest.root=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk \ [2025-11-06T06:44:51.225Z] -Dtest.name=java/net/httpclient/http2/ConnectionFlowControlTest.java \ [2025-11-06T06:44:51.225Z] -Dtest.file=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2/ConnectionFlowControlTest.java \ [2025-11-06T06:44:51.225Z] -Dtest.src=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2 \ [2025-11-06T06:44:51.225Z] -Dtest.src.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.225Z] -Dtest.classes=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d \ [2025-11-06T06:44:51.225Z] -Dtest.class.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.225Z] -Dtest.class.path.prefix=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/java/net/httpclient/http2/ConnectionFlowControlTest.d:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/net/httpclient/http2:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/lib:/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/classes/test/jdk/java/net/httpclient/lib \ [2025-11-06T06:44:51.225Z] -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' \ [2025-11-06T06:44:51.225Z] --add-modules java.base,java.net.http,java.logging,jdk.httpserver \ [2025-11-06T06:44:51.225Z] --add-exports java.base/sun.net.www.http=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] --add-exports java.base/sun.net.www=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] --add-exports java.base/sun.net=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] --add-exports java.net.http/jdk.internal.net.http.common=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] --add-exports java.net.http/jdk.internal.net.http.frame=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] --add-exports java.net.http/jdk.internal.net.http.hpack=ALL-UNNAMED \ [2025-11-06T06:44:51.225Z] -ea \ [2025-11-06T06:44:51.225Z] -esa \ [2025-11-06T06:44:51.225Z] -Xmx512m \ [2025-11-06T06:44:51.225Z] -XX:-UseCompressedOops \ [2025-11-06T06:44:51.225Z] -Djava.library.path=/home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/jdkbinary/openjdk-test-image/jdk/jtreg/native \ [2025-11-06T06:44:51.225Z] -Djdk.internal.httpclient.debug=true \ [2025-11-06T06:44:51.225Z] -Djdk.httpclient.connectionWindowSize=65535 \ [2025-11-06T06:44:51.225Z] -Djdk.httpclient.windowsize=16384 \ [2025-11-06T06:44:51.225Z] com.sun.javatest.regtest.agent.MainWrapper /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work/java/net/httpclient/http2/ConnectionFlowControlTest.d/testng.0.jta java/net/httpclient/http2/ConnectionFlowControlTest.java false ConnectionFlowControlTest [2025-11-06T06:44:51.225Z] [2025-11-06T06:44:51.225Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.Exception: failures: 1 [2025-11-06T06:44:51.225Z] -------------------------------------------------- [2025-11-06T07:32:41.732Z] Test results: passed: 813; failed: 1 [2025-11-06T07:33:01.587Z] Report written to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/report/html/report.html [2025-11-06T07:33:01.587Z] Results written to /home/jenkins/workspace/Test_openjdk17_hs_extended.openjdk_s390x_linux_testList_5/aqa-tests/TKG/output_1762403923729/jdk_net_1/work [2025-11-06T07:33:01.587Z] Error: Some tests failed or other problems occurred. [2025-11-06T07:33:01.587Z] ----------------------------------- [2025-11-06T07:33:01.587Z] jdk_net_1_FAILED [2025-11-06T07:33:01.587Z] ----------------------------------- [2025-11-06T07:33:01.587Z] [2025-11-06T07:33:01.587Z] TEST TEARDOWN: [2025-11-06T07:33:01.587Z] Nothing to be done for teardown. [2025-11-06T07:33:01.587Z] jdk_net_1 Finish Time: Thu Nov 6 02:32:59 2025 Epoch Time (ms): 1762414379359