2025-04-30 09:52:04,607 Generated random file: mgqorxtzfx of size: 5120 2025-04-30 09:52:04,607 Generated random file: efudxclwsp of size: 10240 2025-04-30 09:52:04,607 Requests: https://server6:443/mgqorxtzfx https://server6:443/efudxclwsp 2025-04-30 09:52:04,669 2025-04-30 09:52:04,669 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_ufi147ly/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_0ezwgtbq/ DOWNLOADS=/tmp/download_pijflm67/ SERVER_LOGS=/tmp/logs_server__zn73djd CLIENT_LOGS=/tmp/logs_client_s4cyekz0 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=us-central1-docker.pkg.dev/golang-interop-testing/quic/go-x-net:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/mgqorxtzfx https://server6:443/efudxclwsp" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 09:52:16,740 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + '[' -n transfer ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.sE6yMV9IUM server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.sE6yMV9IUM server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.sE6yMV9IUM -W '' server | pk12util: PKCS12 IMPORT SUCCESSFUL server | + certutil -L -d sql:/neqo/db -n cert server | Certificate: server | Data: server | Version: 3 (0x2) server | Serial Number: server | 2e:87:ec:e6:73:3f:b3:cf:43:07:ec:fe:ed:7a:35:9c: server | ff:bd:46:7b server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Wed Apr 30 09:52:04 2025 server | Not After : Sat May 10 09:52:04 2025 server | Subject: "O=interop runner leaf" server | Subject Public Key Info: server | Public Key Algorithm: X9.62 elliptic curve public key server | Args: server | 06:08:2a:86:48:ce:3d:03:01:07 server | EC Public Key: server | PublicValue: server | 04:c9:ce:32:6b:dd:83:85:51:d6:d6:15:54:4c:33:16: server | c7:17:54:9a:31:03:3f:8a:94:63:c0:a3:66:ba:8a:b8: server | d0:6b:34:f7:eb:71:c1:eb:a7:9b:25:79:a4:b6:a8:b5: server | e1:26:24:b1:fd:a6:e5:3e:c1:27:a3:ed:df:32:61:66: server | e5 server | Curve: ANSI X9.62 elliptic curve prime256v1 (aka secp256r1, NIST P-256) server | Signed Extensions: server | Name: Certificate Subject Alt Name server | DNS name: "server" server | DNS name: "server4" server | DNS name: "server6" server | DNS name: "server46" server | server | Name: Certificate Subject Key ID server | Data: server | 54:fa:a3:7f:8d:c9:f3:d6:2b:23:c1:13:ee:f7:2e:e8: server | 36:1d:0c:92 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 44:43:46:9b:fb:c1:82:a4:27:8e:fc:b4:b3:cb:97:c0: server | 64:88:90:3f server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:20:70:93:f0:14:35:b7:e1:49:ac:fc:50:7a: server | 89:37:70:79:01:7c:c9:9e:0d:72:e7:7c:98:6b:59:01: server | be:a1:d3:0c:02:21:00:a8:79:8e:69:38:22:23:d0:4d: server | 75:ae:76:9b:3e:cf:2d:21:3a:62:c0:64:ed:30:29:a1: server | 30:d2:3d:bf:06:81:78 server | Fingerprint (SHA-256): server | 49:A6:55:35:CD:31:AB:43:23:54:80:DC:BC:45:DB:68:9B:7E:7C:66:86:E4:A4:7F:90:F0:D4:4F:8A:55:E8:BF server | Fingerprint (SHA1): server | 8E:E7:B4:94:D6:E3:39:F9:2A:AD:92:B8:CA:6B:DC:75:FC:4E:52:92 server | server | Mozilla-CA-Policy: false (attribute missing) server | Certificate Trust Flags: server | SSL Flags: server | User server | Email Flags: server | User server | Object Signing Flags: server | User server | server | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT") server | + '[' transfer = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443' server | ++ tee -i -a /logs/server.log server | 0.000 DEBUG Logging initialized server | 0.002 DEBUG Default socket send buffer size is 212992 server | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.002 INFO Server waiting for connection on: [::]:443 server | 0.767 DEBUG [Server] Unsupported version: 57414954 server | 0.767 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:46004 IpTos(Cs0, NotEct) len 15 server | 0.767 DEBUG [Server] Unsupported version: 57414954 server | 0.767 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:46004 IpTos(Cs0, NotEct) len 15 server | 0.767 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.767 DEBUG [Server] Unsupported version: 57414954 server | 0.767 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:46004 IpTos(Cs0, NotEct) len 15 server | 0.767 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | server:443 is available after 1.03120617s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | 2025/04/30 09:52:06 listening on [::]:56154 server | 0.987 DEBUG [Server] Handle initial server | 0.987 INFO AddressValidation: no token; accepting server | 0.987 INFO [Server] Accept connection CID [8]: 704ff5db971e27c3 server | 0.987 DEBUG Overwrite initial version Version1 ==> Version1 server | 0.988 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500 server | 0.988 INFO [Server ...] Received valid Initial packet with scid CID [8]: 3d2ddf921fb453b4 dcid CID [8]: 704ff5db971e27c3 server | 0.988 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=704ff5db971e27c3 server | 0.988 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 0.989 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 0.989 DEBUG [Server 704ff5db971e27c3] State change from Init -> WaitInitial server | 0.989 DEBUG [Server 704ff5db971e27c3] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 296 server | -> RX Crypto { offset: 0, len: 249 } server | 0.989 DEBUG Read Ok(249) bytes server | 0.989 DEBUG 0-RTT: no token, no 0-RTT server | 0.989 DEBUG Read secret available for Handshake: SymKey [32]: d3a044d1d1d43c1df1f1632c0212327ed74241102ce0b16d6e090ba1ed6fc96b server | 0.989 DEBUG Write secret available for Handshake: SymKey [32]: 2e93036614b9bb3023b412bccfcf087494ea968b06abeb93b363c0ba70509c26 server | 0.989 DEBUG Writing transport parameters, msg=8 server | 0.989 DEBUG Read secret available for ApplicationData: SymKey [32]: 8f86f2e4955fc421128837020359b8b757c56b2909f0e28894f7e44d8ab2b3d6 server | 0.989 DEBUG Write secret available for ApplicationData: SymKey [32]: 0f953ad0bfacdf01af162d0298528435422a5f6dd778c160b126116a073a4d69 server | 0.989 DEBUG [Agent 0x55a531cda1d0] state -> InProgress server | 0.990 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 0.990 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 0.990 DEBUG [Crypto] Handshake keys installed server | 0.990 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 0.990 DEBUG [Crypto] Application write key installed server | 0.990 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 405091889 } server | 0.990 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:56154] Make permanent server | 0.990 DEBUG [unv-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154] set as primary path server | 0.990 DEBUG [Server 704ff5db971e27c3] State change from WaitInitial -> Handshaking server | 0.990 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 0.990 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.990 DEBUG Building Initial dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG CRYPTO for in offset=0, len=90 server | 0.990 DEBUG [Server 704ff5db971e27c3] pn=0 type=Initial pri-unv-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 144 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 0.990 DEBUG Building Handshake dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG CRYPTO for hs offset=0, len=726 server | 0.990 DEBUG [Server 704ff5db971e27c3] pn=0 type=Handshake pri-unv-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 918 server | TX -> Crypto { offset: 0, len: 726 } server | 0.990 DEBUG packet_sent this=0x55a531cd9b40, pn=0, ps=774 server | 0.990 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 0.990 DEBUG [Server 704ff5db971e27c3] pad Initial from 918 to PLPMTU 1232 server | 0.990 DEBUG packet_sent this=0x55a531cd9b40, pn=0, ps=458 server | 0.990 DEBUG ECN probing: sent 1 probes server | 0.990 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.990 DEBUG Building Initial dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG Building Handshake dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 0.990 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.990 DEBUG [Server 704ff5db971e27c3] delay duration 297.122074ms server | 0.990 DEBUG Setting timeout of 297.122074ms server | 0.990 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.990 DEBUG Building Initial dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG Building Handshake dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 0.990 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 0.990 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.990 DEBUG [Server 704ff5db971e27c3] delay duration 297.093301ms server | 0.990 DEBUG Setting timeout of 297.093301ms client | 2025/04/30 09:52:06 connected to server6:443 server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=1 type=Initial pri-unv-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 50 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.023 DEBUG [Server 704ff5db971e27c3] Rx ACK space=in, ranges=[0..=0] server | 1.023 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.023 DEBUG on_packets_acked this=0x55a531cd9b40, limited=1, bytes_in_flight=774, cwnd=12320, state=SlowStart, new_acked=458 server | 1.023 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.023 DEBUG [pri-unv-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154] Path validated Instant { tv_sec: 470, tv_nsec: 440983961 } server | 1.023 DEBUG [Server 704ff5db971e27c3] Drop packet number space in server | 1.023 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=0 type=Handshake pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 88 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 1.023 DEBUG [Server 704ff5db971e27c3] Rx ACK space=hs, ranges=[0..=0] server | 1.023 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.023 DEBUG on_packets_acked this=0x55a531cd9b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=774 server | 1.023 DEBUG Acked crypto frame space=hs offset=0 length=726 server | 1.023 DEBUG Read Ok(36) bytes server | 1.023 DEBUG [Agent 0x55a531cda1d0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.023 DEBUG [Server 704ff5db971e27c3] TLS connection complete server | 1.023 DEBUG [pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154] Path validated Instant { tv_sec: 470, tv_nsec: 440983961 } server | 1.023 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.023 DEBUG [Crypto] application read keys installed server | 1.023 DEBUG [Server 704ff5db971e27c3] State change from Handshaking -> Connected server | 1.023 DEBUG [Server 704ff5db971e27c3] State change from Connected -> Confirmed server | 1.023 DEBUG PMTUD started with probe size 1380 server | 1.023 INFO [Server 704ff5db971e27c3] Connection established server | 1.023 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 440983961 } server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=0 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1062 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [245, 11, 55, 43, 210, 227, 148, 26], stateless_reset_token: [72, 246, 210, 193, 56, 224, 109, 86, 70, 216, 190, 39, 101, 206, 164, 244] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [86, 117, 142, 57, 243, 114, 228, 107], stateless_reset_token: [89, 219, 252, 145, 98, 186, 40, 76, 44, 17, 14, 24, 167, 195, 228, 55] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [96, 82, 173, 84, 8, 13, 27, 255], stateless_reset_token: [29, 165, 18, 158, 126, 39, 197, 98, 76, 205, 189, 172, 119, 102, 125, 117] } server | -> RX Padding { len: 950 } server | 1.023 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 460983961 } server | 1.023 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.023 DEBUG Building Handshake dcid Some(CID [8]: 3d2ddf921fb453b4) scid Some(CID [10]: acaa97690bc74d95e779) server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=1 type=Handshake pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 49 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.023 DEBUG [Server 704ff5db971e27c3] Drop packet number space hs server | 1.023 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.023 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=0 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [18, 147, 212, 178, 8, 216, 36, 27, 48, 220], stateless_reset_token: [144, 231, 31, 208, 94, 149, 100, 181, 15, 118, 217, 167, 100, 143, 222, 11] } server | TX -> Padding { len: 1226 } server | 1.023 DEBUG packet_sent this=0x55a531cd9b40, pn=0, ps=1283 server | 1.023 DEBUG ECN probing: sent 2 probes server | 1.023 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.023 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.023 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=1 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.023 DEBUG packet_sent this=0x55a531cd9b40, pn=1, ps=1332 server | 1.023 DEBUG ECN probing: sent 3 probes server | 1.023 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.023 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.023 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.023 DEBUG [Server 704ff5db971e27c3] delay duration 1.366644ms server | 1.023 DEBUG Setting timeout of 1.366644ms server | 1.023 DEBUG [Server 704ff5db971e27c3] pn=1 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 48 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 1.024 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 441652655 } server | 1.024 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.024 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.024 DEBUG [Server 704ff5db971e27c3] pn=2 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 31 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.024 DEBUG ECN probing: sent 4 probes server | 1.024 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.024 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.024 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.024 DEBUG [Server 704ff5db971e27c3] delay duration 1.309801ms server | 1.024 DEBUG Setting timeout of 1.309801ms server | 1.024 DEBUG [Server 704ff5db971e27c3] pn=2 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 48 server | -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true } server | 1.024 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 461761688 } server | 1.024 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.024 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.024 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.024 DEBUG [Server 704ff5db971e27c3] delay duration 1.283532ms server | 1.024 DEBUG Setting timeout of 1.283532ms server | 1.024 DEBUG [Server 704ff5db971e27c3] send session ticket 40630008704ff5db971e27c30104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0aacaa97690bc74d95e779110c000000014aba7aea000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.025 DEBUG Path = 'mgqorxtzfx' server | 1.025 DEBUG Path = 'efudxclwsp' server | 1.025 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.025 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.025 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.025 DEBUG [Server 704ff5db971e27c3] delay duration 275.767µs server | 1.025 DEBUG Setting timeout of 275.767µs server | 1.026 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.026 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.026 DEBUG [Server 704ff5db971e27c3] pn=3 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 1.026 DEBUG packet_sent this=0x55a531cd9b40, pn=3, ps=1232 server | 1.026 DEBUG ECN probing: sent 5 probes server | 1.026 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.026 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.026 DEBUG [Server 704ff5db971e27c3] pn=4 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 1.026 DEBUG packet_sent this=0x55a531cd9b40, pn=4, ps=1232 server | 1.026 DEBUG ECN probing: sent 6 probes server | 1.026 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.026 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.026 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.026 DEBUG [Server 704ff5db971e27c3] delay duration 1.749248ms server | 1.026 DEBUG Setting timeout of 1.749248ms server | 1.026 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.026 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.026 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.026 DEBUG [Server 704ff5db971e27c3] delay duration 1.733418ms server | 1.026 DEBUG Setting timeout of 1.733418ms server | 1.029 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.029 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.029 DEBUG [Server 704ff5db971e27c3] pn=5 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 1.029 DEBUG packet_sent this=0x55a531cd9b40, pn=5, ps=1232 server | 1.029 DEBUG ECN probing: sent 7 probes server | 1.029 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.029 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.029 DEBUG [Server 704ff5db971e27c3] pn=6 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false } server | 1.029 DEBUG packet_sent this=0x55a531cd9b40, pn=6, ps=1232 server | 1.029 DEBUG ECN probing: sent 8 probes server | 1.029 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.029 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.029 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.029 DEBUG [Server 704ff5db971e27c3] delay duration 1.743217ms server | 1.029 DEBUG Setting timeout of 1.743217ms server | 1.029 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.029 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.029 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.029 DEBUG [Server 704ff5db971e27c3] delay duration 1.727177ms server | 1.029 DEBUG Setting timeout of 1.727177ms server | 1.032 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.032 DEBUG [Server 704ff5db971e27c3] pn=7 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4810, len: 310, fin: true } server | TX -> Stream { stream_id: 4, offset: 0, len: >>888, fin: false } server | 1.032 DEBUG packet_sent this=0x55a531cd9b40, pn=7, ps=1232 server | 1.032 DEBUG ECN probing: sent 9 probes server | 1.032 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.032 DEBUG [Server 704ff5db971e27c3] pn=8 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 4, offset: 888, len: >>1202, fin: false } server | 1.032 DEBUG packet_sent this=0x55a531cd9b40, pn=8, ps=1232 server | 1.032 DEBUG ECN probing: sent 10 probes server | 1.032 DEBUG ECN probing concluded with 10 probes sent server | 1.032 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG [Server 704ff5db971e27c3] delay duration 1.752555ms server | 1.032 DEBUG Setting timeout of 1.752555ms server | 1.032 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG [Server 704ff5db971e27c3] delay duration 1.736334ms server | 1.032 DEBUG Setting timeout of 1.736334ms server | 1.035 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.035 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.035 DEBUG [Server 704ff5db971e27c3] pn=9 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 4, offset: 2090, len: >>1202, fin: false } server | 1.035 DEBUG packet_sent this=0x55a531cd9b40, pn=9, ps=1232 server | 1.035 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1081, pto: None, probe: EnumSet(), paced: false } server | 1.035 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.035 DEBUG [Server 704ff5db971e27c3] pn=10 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1081 server | TX -> Stream { stream_id: 4, offset: 3292, len: >>1051, fin: false } server | 1.035 DEBUG packet_sent this=0x55a531cd9b40, pn=10, ps=1081 server | 1.036 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG [Server 704ff5db971e27c3] delay duration 8.073252ms server | 1.036 DEBUG Setting timeout of 8.073252ms server | 1.036 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG [Server 704ff5db971e27c3] delay duration 8.053075ms server | 1.036 DEBUG Setting timeout of 8.053075ms server | 1.045 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.045 DEBUG [Server 704ff5db971e27c3] pn=11 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 32 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 2629, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.045 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG [Server 704ff5db971e27c3] delay duration 105.497842ms server | 1.045 DEBUG Setting timeout of 105.497842ms server | 1.045 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG [Server 704ff5db971e27c3] delay duration 105.473126ms server | 1.045 DEBUG Setting timeout of 105.473126ms client | 2025/04/30 09:52:06 fetched https://server6:443/mgqorxtzfx server | 1.056 DEBUG [Server 704ff5db971e27c3] pn=3 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.056 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=1] server | 1.056 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 1.056 WARN ECN validation failed, no ECN counts in ACK frame server | 1.056 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] slow start += 2615 server | 1.056 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615 server | 1.056 DEBUG PMTUD probe of size 1380 succeeded server | 1.056 DEBUG PMTUD started with probe size 1420 server | 1.056 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.056 DEBUG [Server 704ff5db971e27c3] pn=12 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 4, offset: 4343, len: >>1341, fin: false } server | 1.056 DEBUG packet_sent this=0x55a531cd9b40, pn=12, ps=1372 server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG [Server 704ff5db971e27c3] pn=13 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 5684, len: >>1302, fin: false } server | 1.056 DEBUG packet_sent this=0x55a531cd9b40, pn=13, ps=1332 server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG [Server 704ff5db971e27c3] pn=14 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 6986, len: >>1302, fin: false } server | 1.056 DEBUG packet_sent this=0x55a531cd9b40, pn=14, ps=1332 server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1194, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG [Server 704ff5db971e27c3] pn=15 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1194 server | TX -> Stream { stream_id: 4, offset: 8288, len: >>1164, fin: false } server | 1.056 DEBUG packet_sent this=0x55a531cd9b40, pn=15, ps=1194 server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG [Server 704ff5db971e27c3] delay duration 104.00451ms server | 1.056 DEBUG Setting timeout of 104.00451ms server | 1.056 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG [Server 704ff5db971e27c3] delay duration 103.983972ms server | 1.056 DEBUG Setting timeout of 103.983972ms server | 1.058 DEBUG [Server 704ff5db971e27c3] pn=4 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: None } server | 1.058 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=4] server | 1.058 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.058 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12471/17399 ssthresh 18446744073709551615] slow start += 2464 server | 1.058 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12471/17399 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=12471, cwnd=17399, state=SlowStart, new_acked=2464 server | 1.058 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.058 DEBUG CRYPTO for ap offset=0, len=305 server | 1.058 DEBUG [Server 704ff5db971e27c3] pn=16 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1174 server | TX -> Stream { stream_id: 4, offset: 9452, len: 788, fin: true } server | TX -> Crypto { offset: 0, len: 305 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 163, 245, 103, 7, 235, 20, 222, 250, 175, 122, 36, 12, 167, 137, 86, 234, 174, 52, 101, 113, 215, 122, 216, 97, 84, 211, 231, 9, 239, 19, 67, 41, 96, 119, 3, 144] } server | 1.058 DEBUG packet_sent this=0x55a531cd9b40, pn=16, ps=1174 server | 1.058 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG [Server 704ff5db971e27c3] delay duration 95.711626ms server | 1.058 DEBUG Setting timeout of 95.711626ms server | 1.058 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG [Server 704ff5db971e27c3] delay duration 95.68697ms server | 1.058 DEBUG Setting timeout of 95.68697ms server | 1.061 DEBUG [Server 704ff5db971e27c3] pn=5 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 1.061 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=6] server | 1.061 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.061 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11181/19863 ssthresh 18446744073709551615] slow start += 2464 server | 1.061 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11181/19863 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=11181, cwnd=19863, state=SlowStart, new_acked=2464 server | 1.061 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.062 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.062 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.062 DEBUG [Server 704ff5db971e27c3] delay duration 85.999455ms server | 1.062 DEBUG Setting timeout of 85.999455ms server | 1.062 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.062 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.062 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.062 DEBUG [Server 704ff5db971e27c3] delay duration 85.940365ms server | 1.062 DEBUG Setting timeout of 85.940365ms server | 1.065 DEBUG [Server 704ff5db971e27c3] pn=6 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 1.065 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=8] server | 1.065 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.065 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8717/22327 ssthresh 18446744073709551615] slow start += 2464 server | 1.065 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8717/22327 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=8717, cwnd=22327, state=SlowStart, new_acked=2464 server | 1.065 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.065 DEBUG [Server 704ff5db971e27c3] pn=17 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 28 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | 1.065 DEBUG packet_sent this=0x55a531cd9b40, pn=17, ps=29 server | 1.065 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG [Server 704ff5db971e27c3] delay duration 83.70722ms server | 1.065 DEBUG Setting timeout of 83.70722ms server | 1.065 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG [Server 704ff5db971e27c3] delay duration 83.682203ms server | 1.065 DEBUG Setting timeout of 83.682203ms server | 1.067 DEBUG [Server 704ff5db971e27c3] pn=7 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 38 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 6, first_ack_range: 9, ack_ranges: [], ecn_count: None } server | -> RX MaxData { maximum_data: 73948 } server | 1.067 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=9] server | 1.067 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=9 server | 1.067 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7514/23559 ssthresh 18446744073709551615] slow start += 1232 server | 1.067 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7514/23559 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=7514, cwnd=23559, state=SlowStart, new_acked=1232 server | 1.067 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 505108933 } server | 1.067 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.067 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.067 DEBUG [Server 704ff5db971e27c3] delay duration 20ms server | 1.067 DEBUG Setting timeout of 20ms server | 1.067 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.067 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.067 DEBUG [Server 704ff5db971e27c3] delay duration 19.944277ms server | 1.067 DEBUG Setting timeout of 19.944277ms client | 2025/04/30 09:52:06 fetched https://server6:443/efudxclwsp server | 1.088 DEBUG [Server 704ff5db971e27c3] pn=8 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 12, ack_delay: 0, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | 1.088 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=12] server | 1.088 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12 server | 1.088 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5061/26012 ssthresh 18446744073709551615] slow start += 2453 server | 1.088 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5061/26012 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=5061, cwnd=26012, state=SlowStart, new_acked=2453 server | 1.088 DEBUG PMTUD probe of size 1420 succeeded server | 1.088 DEBUG PMTUD started with probe size 1470 server | 1.088 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 1.088 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.088 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.088 DEBUG Sending PMTUD probe of size 1470, count 1 server | 1.088 DEBUG [Server 704ff5db971e27c3] pn=18 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 1422 server | TX -> Ack { largest_acknowledged: 8, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | TX -> Ping server | TX -> Padding { len: 1390 } server | 1.088 DEBUG packet_sent this=0x55a531cd9b40, pn=18, ps=1422 server | 1.088 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.088 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.088 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.088 DEBUG [Server 704ff5db971e27c3] delay duration 76.920193ms server | 1.088 DEBUG Setting timeout of 76.920193ms server | 1.088 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.088 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.088 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.088 DEBUG [Server 704ff5db971e27c3] delay duration 76.889256ms server | 1.088 DEBUG Setting timeout of 76.889256ms server | 1.090 DEBUG [Server 704ff5db971e27c3] pn=9 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 0, first_ack_range: 14, ack_ranges: [], ecn_count: None } server | 1.090 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=14] server | 1.090 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14 server | 1.090 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3819/28676 ssthresh 18446744073709551615] slow start += 2664 server | 1.090 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3819/28676 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=3819, cwnd=28676, state=SlowStart, new_acked=2664 server | 1.090 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.090 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG [Server 704ff5db971e27c3] delay duration 70.518642ms server | 1.090 DEBUG Setting timeout of 70.518642ms server | 1.090 DEBUG [Server 704ff5db971e27c3] pn=10 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 34 server | -> RX MaxStreamData { stream_id: StreamId(4), maximum_stream_data: 73824 } server | 1.090 DEBUG setting max_stream_data to 73824 server | 1.090 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 470, tv_nsec: 528267686 } server | 1.090 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.090 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG [Server 704ff5db971e27c3] delay duration 20ms server | 1.090 DEBUG Setting timeout of 20ms server | 1.090 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.090 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG [Server 704ff5db971e27c3] delay duration 19.966938ms server | 1.090 DEBUG Setting timeout of 19.966938ms server | 1.092 DEBUG [Server 704ff5db971e27c3] pn=11 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 16, ack_delay: 0, first_ack_range: 16, ack_ranges: [], ecn_count: None } server | 1.092 DEBUG [Server 704ff5db971e27c3] Rx ACK space=ap, ranges=[0..=16] server | 1.092 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=16 server | 1.092 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/31044 ssthresh 18446744073709551615] slow start += 2368 server | 1.092 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/31044 ssthresh 18446744073709551615] on_packets_acked this=0x55a531cd9b40, limited=0, bytes_in_flight=1451, cwnd=31044, state=SlowStart, new_acked=2368 server | 1.092 DEBUG Acked crypto frame space=ap offset=0 length=305 server | 1.092 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.092 DEBUG [Server 704ff5db971e27c3] pn=19 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 28 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 18 } server | 1.092 DEBUG packet_sent this=0x55a531cd9b40, pn=19, ps=29 server | 1.092 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.092 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG [Server 704ff5db971e27c3] delay duration 18.005629ms server | 1.092 DEBUG Setting timeout of 18.005629ms server | 1.092 DEBUG [Server 704ff5db971e27c3] pn=12 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 32 server | -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" } server | 1.092 INFO [Server 704ff5db971e27c3] ConnectionClose received. Error code: Transport(0) frame type 0 reason server | 1.092 DEBUG [Server 704ff5db971e27c3] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 470, tv_nsec: 717969335 } } server | 1.092 DEBUG [pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154] Path validated Instant { tv_sec: 470, tv_nsec: 510288797 } server | 1.092 DEBUG [Server 704ff5db971e27c3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [8]: 3d2ddf921fb453b4) server | 1.092 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 470, tv_nsec: 510288797 } server | 1.092 DEBUG [Server 704ff5db971e27c3] pn=20 type=Short pri-path:3d2ddf921fb453b4 [::]:443->[fd00:cafe:cafe::100]:56154 IpTos(Cs0, NotEct) len 35 server | TX -> Ack { largest_acknowledged: 12, ack_delay: 0, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" } server | 1.092 DEBUG Setting timeout of 207.598498ms server | 1.092 DEBUG Setting timeout of 207.58865ms client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 09:52:16,840 Using the client's key log file. 2025-04-30 09:52:16,851 2025-04-30 09:52:16,852 Using the client's key log file. 2025-04-30 09:52:16,852 Using the client's key log file. 2025-04-30 09:52:16,862 2025-04-30 09:52:16,863 Using the client's key log file. 2025-04-30 09:52:17,431 Check of downloaded files succeeded. 2025-04-30 09:52:18,001 Check of downloaded files succeeded.