2025-09-11 19:39:15,475 Generated random file: hecadrceej of size: 10240 2025-09-11 19:39:15,475 Requests: https://server4:443/hecadrceej 2025-09-11 19:39:15,532 2025-09-11 19:39:15,532 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_izywbm75/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_39iw7r7p/ DOWNLOADS=/tmp/download_6h8sjfqq/ SERVER_LOGS=/tmp/logs_server_3twanjiy CLIENT_LOGS=/tmp/logs_client_ex6gowre SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/alibaba/xquic/xquic-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/hecadrceej" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-09-11 19:39:28,104 Container client Recreate Container server Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 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 | 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 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 retry ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.g72yHV7qVb server | + mkdir -p /neqo/db client | Endpoint's IPv6 address is fd00:cafe:cafe::100 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.g72yHV7qVb client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.g72yHV7qVb -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 | 5a:e7:8e:c2:06:1a:4a:d7:38:c4:8f:9c:24:19:6d:b8: server | b0:dd:18:92 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Thu Sep 11 19:39:15 2025 server | Not After : Sun Sep 21 19:39:15 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:24:f9:3f:65:5d:ec:04:fd:08:41:89:13:a8:19:f1: server | 83:e4:1d:c9:72:35:d0:bb:b7:54:14:24:7d:ab:89:0a: server | 28:33:af:23:6f:14:a7:d1:19:8e:c0:5d:ec:42:e4:12: server | d8:01:db:4e:6e:2a:d7:de:c1:86:e4:95:36:b4:b1:d8: server | 9c 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 | 05:29:3d:56:f8:b0:94:cc:c4:be:37:69:0d:b6:7f:01: server | 87:ce:b7:81 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 20:81:8d:2b:47:99:0d:d4:56:0c:e2:b4:55:ec:53:5b: server | 86:2c:99:e1 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:b7:ae:2d:1b:bc:56:6e:7e:14:6f:6d: server | bb:75:a6:cb:ce:e3:d8:ef:41:8e:ce:6f:9c:02:fa:de: server | 65:d3:5a:5b:f5:02:21:00:e6:c6:6a:b6:1c:10:b1:ea: server | bd:f5:01:5b:19:5e:ae:6b:d6:46:50:3d:e7:1c:29:87: server | 9c:41:64:9b:e5:75:9a:a2 server | Fingerprint (SHA-256): server | 46:F0:21:72:0D:12:CE:79:07:2E:91:C6:7E:94:B1:68:86:19:5E:9D:6C:F4:D5:36:3C:71:D3:50:C0:97:26:BD server | Fingerprint (SHA1): server | 2F:FC:07:5B:56:80:64:B7:FB:9C:6F:B5:14:9B:A9:FB:BB:86:01:F2 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 | + '[' retry = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test retry --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 Ok(212992) server | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.002 INFO Server waiting for connection on: Ok([::]:443) server | 0.283 DEBUG [Server] Unsupported version: 57414954 server | 0.283 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:44620 Tos(Cs0, NotEct) len 15 sim | server:443 is available after 501.354285ms sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | ./demo_client -l d -L /logs/client.log -D /downloads -k /logs/keys.log -K 30 -o -U "https://server4:443/hecadrceej" client | client | option log level :d client | option log directory :/logs/client.log client | option save body dir: /downloads client | key output file: /logs/keys.log client | client life circle time: 30 client | set interop mode client | option url only:https://server4:443/hecadrceej client | server[server4] addr: 193.167.100.100:443. client | No.0 path created id = 0 client | open file[/downloads/hecadrceej] suc server | 1.002 DEBUG [Server] Handle initial server | 1.002 INFO AddressValidation: no token; validating server | 1.002 INFO [Server] Send retry for CID [8]: 5d54a7ac71f536aa server | 1.002 DEBUG [Server] type=Retry path:5d54a7ac71f536aa [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 92 server | 1.034 DEBUG [Server] Handle initial server | 1.034 INFO AddressValidation: valid Retry token for 5d54a7ac71f536aa server | 1.034 INFO [Server] Accept connection CID [8]: 5d54a7ac71f536aa server | 1.034 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.035 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.035 INFO [Server ...] Received valid Initial packet with scid CID [8]: a7f1c021b17425a7 dcid CID [10]: 4629e7ee9fc824e3dfff server | 1.035 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=4629e7ee9fc824e3dfff server | 1.035 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=16 server | 1.035 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.035 DEBUG [Server 4629e7ee9fc824e3dfff] State change from Init -> WaitInitial server | 1.035 DEBUG [Server 4629e7ee9fc824e3dfff] pn=1 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 1200 server | -> RX Crypto { offset: 0, len: 305 } server | -> RX Padding { len: 792 } server | 1.035 DEBUG 0-RTT: no token, no 0-RTT server | 1.036 DEBUG Read secret available for Handshake: SymKey [32]: 38907233f1242767847751e5f5f0f5a33361c7f2584be4d9a23992758467b392 server | 1.036 DEBUG Write secret available for Handshake: SymKey [32]: 2e5d5ef02b9a27f790bba8115b8ec23bb66be2e59a42a808c2ed306e0b8948e9 server | 1.036 DEBUG Writing transport parameters, msg=8 server | 1.037 DEBUG Read secret available for ApplicationData: SymKey [32]: 206944d8eb6e324c0fb0c53c110c1454e45e8f2a2c62cd94a1584777e37005cc server | 1.037 DEBUG Write secret available for ApplicationData: SymKey [32]: 2a4f9ce70a09f8402b39922108fe50ace6a76a26f88b015d7cb876d1abb1310b server | 1.037 DEBUG [Agent 0x5605d815c9f0] state -> InProgress server | 1.037 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.037 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.037 DEBUG [Crypto] Handshake keys installed server | 1.037 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.037 DEBUG [Crypto] Application write key installed server | 1.037 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 369, tv_nsec: 861530131 } server | 1.037 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:36228] Make permanent server | 1.037 DEBUG [unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228] set as primary path server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] State change from WaitInitial -> Handshaking server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG Building Initial dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG CRYPTO for in offset=0, len=123 server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] pn=16 type=Initial pri-unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 177 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 123 } server | 1.037 DEBUG Building Handshake dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG CRYPTO for hs offset=0, len=739 server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] pn=0 type=Handshake pri-unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 964 server | TX -> Crypto { offset: 0, len: 739 } server | 1.037 DEBUG packet_sent this=0x5605d81996d0, pn=0, ps=787 server | 1.037 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] pad Initial from 964 to PLPMTU 1232 server | 1.037 DEBUG packet_sent this=0x5605d81996d0, pn=16, ps=445 server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG Building Initial dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG Building Handshake dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 296.777009ms server | 1.037 DEBUG Setting timeout of 296.777009ms server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG Building Initial dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG Building Handshake dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.037 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 296.74025ms server | 1.037 DEBUG Setting timeout of 296.74025ms server | 1.070 DEBUG [Server 4629e7ee9fc824e3dfff] Drop packet number space in server | 1.070 DEBUG [recovery::Loss] Reset loss recovery state for Initial server | 1.070 INFO [pri-unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228] discarding a packet without an RTT estimate; guessing RTT=36.695707ms server | 1.070 DEBUG [Server 4629e7ee9fc824e3dfff] pn=0 type=Handshake pri-unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 86 server | -> RX Crypto { offset: 0, len: 36 } server | 1.071 DEBUG [Agent 0x5605d815c9f0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 23, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] TLS connection complete server | 1.071 DEBUG [pri-unv-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228] Path validated Instant { tv_sec: 369, tv_nsec: 898225838 } server | 1.071 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.071 DEBUG [Crypto] application read keys installed server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] State change from Handshaking -> Connected server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] State change from Connected -> Confirmed server | 1.071 DEBUG PMTUD started with probe size 1380 server | 1.071 INFO [Server 4629e7ee9fc824e3dfff] Connection established server | 1.071 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 369, tv_nsec: 898225838 } server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG Building Handshake dcid Some(CID [8]: a7f1c021b17425a7) scid Some(CID [10]: 24ae657409a0d9efd607) server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] pn=1 type=Handshake pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 49 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] Drop packet number space hs server | 1.071 DEBUG [recovery::Loss] Reset loss recovery state for Handshake server | 1.071 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] pn=0 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [217, 75, 30, 223, 16, 4, 172, 126, 227, 100], stateless_reset_token: [5, 241, 20, 190, 197, 228, 179, 29, 189, 38, 157, 75, 238, 92, 228, 78] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [121, 160, 133, 148, 135, 95, 40, 212, 64, 243], stateless_reset_token: [134, 150, 194, 124, 51, 185, 57, 40, 220, 123, 218, 89, 65, 105, 29, 79] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [130, 83, 94, 43, 191, 19, 142, 50, 237, 82], stateless_reset_token: [83, 185, 248, 82, 1, 173, 213, 147, 221, 251, 129, 189, 15, 200, 4, 192] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [95, 38, 34, 70, 4, 180, 180, 55, 222, 171], stateless_reset_token: [162, 107, 233, 30, 121, 87, 213, 248, 64, 96, 214, 241, 87, 154, 107, 45] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [253, 68, 220, 3, 227, 115, 230, 152, 159, 70], stateless_reset_token: [110, 178, 4, 62, 4, 72, 178, 168, 184, 108, 98, 140, 112, 171, 191, 186] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [102, 84, 75, 40, 112, 156, 104, 81, 58, 73], stateless_reset_token: [92, 129, 152, 113, 86, 195, 11, 164, 125, 165, 168, 241, 142, 82, 217, 116] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [161, 30, 194, 185, 125, 177, 6, 69, 94, 123], stateless_reset_token: [87, 61, 197, 42, 112, 131, 181, 18, 56, 193, 169, 123, 62, 250, 156, 31] } server | TX -> Padding { len: 1046 } server | 1.071 DEBUG packet_sent this=0x5605d81996d0, pn=0, ps=1283 server | 1.071 DEBUG ECN probing: sent 1 probes server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.071 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] pn=1 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.071 DEBUG packet_sent this=0x5605d81996d0, pn=1, ps=1332 server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.071 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.071 DEBUG ECN probing: sent 2 probes server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.071 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.071 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.574179ms server | 1.071 DEBUG Setting timeout of 1.574179ms server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] send session ticket 407000085d54a7ac71f536aa0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a24ae657409a0d9efd607100a4629e7ee9fc824e3dfff110c000000014afaaaca000000016ab200c0000000ff02de1a0243e8200244b0686921 server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 461.517µs server | 1.072 DEBUG Setting timeout of 461.517µs server | 1.072 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 430.96µs server | 1.072 DEBUG Setting timeout of 430.96µs server | 1.072 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 2 server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 405.472µs server | 1.072 DEBUG Setting timeout of 405.472µs server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] pn=0 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 52 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 1.072 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 369, tv_nsec: 919901874 } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 384.203µs server | 1.072 DEBUG Setting timeout of 384.203µs server | 1.072 DEBUG Path = 'hecadrceej' server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.072 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 298.532µs server | 1.072 DEBUG Setting timeout of 298.532µs server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.074 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] pn=2 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 1.074 DEBUG packet_sent this=0x5605d81996d0, pn=2, ps=1232 server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.074 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] pn=3 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 1.074 DEBUG packet_sent this=0x5605d81996d0, pn=3, ps=1232 server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG ECN probing: sent 4 probes server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.707905ms server | 1.074 DEBUG Setting timeout of 1.707905ms server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.074 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.685663ms server | 1.074 DEBUG Setting timeout of 1.685663ms server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.077 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] pn=4 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 1.077 DEBUG packet_sent this=0x5605d81996d0, pn=4, ps=1232 server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.077 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG ECN probing: sent 5 probes server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.077 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.373292ms server | 1.077 DEBUG Setting timeout of 1.373292ms server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.077 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.077 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.35604ms server | 1.077 DEBUG Setting timeout of 1.35604ms server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.079 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] pn=5 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false } server | 1.079 DEBUG packet_sent this=0x5605d81996d0, pn=5, ps=1232 server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.079 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG ECN probing: sent 6 probes server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.079 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.028005ms server | 1.079 DEBUG Setting timeout of 1.028005ms server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.079 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.079 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.008428ms server | 1.079 DEBUG Setting timeout of 1.008428ms server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.081 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] pn=6 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4810, len: >>1202, fin: false } server | 1.081 DEBUG packet_sent this=0x5605d81996d0, pn=6, ps=1232 server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.081 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] pn=7 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 6012, len: >>1202, fin: false } server | 1.081 DEBUG packet_sent this=0x5605d81996d0, pn=7, ps=1232 server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.081 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG ECN probing: sent 8 probes server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.081 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.716173ms server | 1.081 DEBUG Setting timeout of 1.716173ms server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.081 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.081 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 1.692188ms server | 1.081 DEBUG Setting timeout of 1.692188ms server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] pn=8 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 7214, len: >>1202, fin: false } server | 1.084 DEBUG packet_sent this=0x5605d81996d0, pn=8, ps=1232 server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1081, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] pn=9 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, Ect0) len 1081 server | TX -> Stream { stream_id: 0, offset: 8416, len: >>1051, fin: false } server | 1.084 DEBUG packet_sent this=0x5605d81996d0, pn=9, ps=1081 server | 1.084 DEBUG ECN probing: sent 10 probes server | 1.084 DEBUG ECN probing concluded with 10 probes sent server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 7.882665ms server | 1.084 DEBUG Setting timeout of 7.882665ms server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 7.861195ms server | 1.084 DEBUG Setting timeout of 7.861195ms server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] pn=10 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 32 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 2662, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 125.733892ms server | 1.093 DEBUG Setting timeout of 125.733892ms server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 125.713454ms server | 1.093 DEBUG Setting timeout of 125.713454ms server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] pn=1 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 59 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [6, 8, 195, 119, 184, 27, 204, 133], stateless_reset_token: [70, 111, 63, 200, 40, 151, 60, 2, 208, 209, 196, 16, 112, 100, 226, 188] } server | 1.103 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 369, tv_nsec: 950553847 } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.103 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 20ms server | 1.103 DEBUG Setting timeout of 20ms server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] pn=2 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 59 server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [92, 238, 58, 247, 46, 203, 160, 3], stateless_reset_token: [193, 55, 204, 94, 19, 185, 220, 137, 58, 133, 89, 138, 121, 194, 35, 173] } server | 1.103 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 369, tv_nsec: 930637844 } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] pn=11 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 31 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.103 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 116.290561ms server | 1.103 DEBUG Setting timeout of 116.290561ms server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.103 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 116.269171ms server | 1.103 DEBUG Setting timeout of 116.269171ms server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] pn=6 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 36 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 12, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=1] server | 1.103 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1 server | 1.103 WARN ECN validation failed, no ECN counts in ACK frame server | 1.103 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.103 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615 server | 1.103 DEBUG PMTUD probe of size 1380 succeeded server | 1.103 DEBUG PMTUD started with probe size 1420 server | 1.103 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.103 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.103 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.103 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.103 DEBUG CRYPTO for ap offset=0, len=321 server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] pn=12 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 9467, len: 773, fin: true } server | TX -> Crypto { offset: 0, len: 321 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 219, 100, 69, 211, 74, 202, 66, 95, 236, 177, 234, 107, 227, 221, 209, 208, 209, 238, 27, 94, 59, 254, 240, 194, 220, 253, 87, 164, 212, 152, 63, 72, 233, 204, 200, 224] } server | TX -> Padding { len: 196 } server | 1.104 DEBUG packet_sent this=0x5605d81996d0, pn=12, ps=1372 server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.104 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.104 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 120.155652ms server | 1.104 DEBUG Setting timeout of 120.155652ms server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.104 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.104 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 120.131075ms server | 1.104 DEBUG Setting timeout of 120.131075ms server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] pn=7 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 36 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 14, first_ack_range: 3, ack_ranges: [], ecn_count: None } server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=3] server | 1.107 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=3 server | 1.107 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8613/17399 ssthresh 18446744073709551615] slow start += 2464 server | 1.107 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8613/17399 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=8613, cwnd=17399, state=SlowStart, new_acked=2464 server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.107 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.107 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 105.264354ms server | 1.107 DEBUG Setting timeout of 105.264354ms server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.107 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.107 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.107 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 105.206896ms server | 1.107 DEBUG Setting timeout of 105.206896ms server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] pn=8 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 36 server | -> RX Ack { largest_acknowledged: 5, ack_delay: 15, first_ack_range: 5, ack_ranges: [], ecn_count: None } server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=5] server | 1.110 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=5 server | 1.110 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6149/19863 ssthresh 18446744073709551615] slow start += 2464 server | 1.110 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6149/19863 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=6149, cwnd=19863, state=SlowStart, new_acked=2464 server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.110 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.110 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 93.564257ms server | 1.110 DEBUG Setting timeout of 93.564257ms server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.110 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.110 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.110 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 93.498644ms server | 1.110 DEBUG Setting timeout of 93.498644ms server | 1.113 DEBUG [Server 4629e7ee9fc824e3dfff] pn=9 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 36 server | -> RX Ack { largest_acknowledged: 7, ack_delay: 14, first_ack_range: 7, ack_ranges: [], ecn_count: None } server | 1.113 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=7] server | 1.113 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=7 server | 1.113 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3685/22327 ssthresh 18446744073709551615] slow start += 2464 server | 1.113 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3685/22327 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=3685, cwnd=22327, state=SlowStart, new_acked=2464 server | 1.113 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.113 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.114 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.114 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 82.689493ms server | 1.114 DEBUG Setting timeout of 82.689493ms server | 1.114 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.114 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.114 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.114 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 82.62362ms server | 1.114 DEBUG Setting timeout of 82.62362ms server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] pn=10 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 36 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 12, first_ack_range: 9, ack_ranges: [], ecn_count: None } server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=9] server | 1.117 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=9 server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] slow start += 2313 server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=1372, cwnd=24640, state=SlowStart, new_acked=2313 server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 73.575047ms server | 1.117 DEBUG Setting timeout of 73.575047ms server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 73.513822ms server | 1.117 DEBUG Setting timeout of 73.513822ms client | >>>>>>>> request time cost:139258 us, speed:73 K/s client | >>>>>>>> user_stream[0x55a1426ea2f0], req: /hecadrceej, send_body_size:11, recv_body_size:10240 server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] pn=11 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 37 server | -> RX Ack { largest_acknowledged: 12, ack_delay: 3236, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=12] server | 1.161 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=12 server | 1.161 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] slow start += 1372 server | 1.161 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] on_packets_acked this=0x5605d81996d0, limited=0, bytes_in_flight=0, cwnd=26012, state=SlowStart, new_acked=1372 server | 1.161 DEBUG PMTUD probe of size 1420 succeeded server | 1.161 DEBUG PMTUD started with probe size 1470 server | 1.161 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 1.161 DEBUG Acked crypto frame space=ap offset=0 length=321 server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.161 DEBUG Sending PMTUD probe of size 1470, count 1 server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] pn=13 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 1422 server | TX -> Ping server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | TX -> Padding { len: 1393 } server | 1.161 DEBUG packet_sent this=0x5605d81996d0, pn=13, ps=1422 server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.161 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.161 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 81.598163ms server | 1.161 DEBUG Setting timeout of 81.598163ms server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.161 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.161 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 81.573857ms server | 1.161 DEBUG Setting timeout of 81.573857ms server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] pn=12 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 37 server | -> RX Ack { largest_acknowledged: 13, ack_delay: 3212, first_ack_range: 13, ack_ranges: [], ecn_count: None } server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=13] server | 1.218 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=13 server | 1.218 DEBUG on_packets_acked this=0x5605d81996d0, limited=1, bytes_in_flight=0, cwnd=26012, state=SlowStart, new_acked=1422 server | 1.218 DEBUG PMTUD probe of size 1470 succeeded server | 1.218 DEBUG PMTUD started with probe size 1500 server | 1.218 DEBUG PLPMTU changed from 1372 to 1422, updating pacer server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.218 DEBUG Sending PMTUD probe of size 1500, count 1 server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] pn=14 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 1452 server | TX -> Ping server | TX -> Padding { len: 1425 } server | 1.218 DEBUG packet_sent this=0x5605d81996d0, pn=14, ps=1452 server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.218 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.218 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 77.663028ms server | 1.218 DEBUG Setting timeout of 77.663028ms server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.218 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 1.218 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 77.640907ms server | 1.218 DEBUG Setting timeout of 77.640907ms server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] pn=13 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 37 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 3212, first_ack_range: 14, ack_ranges: [], ecn_count: None } server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] Rx ACK space=ap, ranges=[0..=14] server | 1.276 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=14 server | 1.276 DEBUG on_packets_acked this=0x5605d81996d0, limited=1, bytes_in_flight=0, cwnd=26012, state=SlowStart, new_acked=1452 server | 1.276 DEBUG PMTUD probe of size 1500 succeeded server | 1.276 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 970, tv_nsec: 103561499 }) server | 1.276 DEBUG PLPMTU changed from 1422 to 1452, updating pacer server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } server | 1.276 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.276 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 30s server | 1.276 DEBUG Setting timeout of 30s server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } server | 1.276 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.276 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } server | 1.276 DEBUG [Server 4629e7ee9fc824e3dfff] delay duration 29.999921072s server | 1.276 DEBUG Setting timeout of 29.999921072s client | [HQ-req] send_bytes:17, recv_bytes:10240, path_info:0-1-9-17-10240 client | task[0], fin_cnt: 1, fin_flag: 1 server | 1.428 DEBUG [Server 4629e7ee9fc824e3dfff] pn=14 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 35 server | -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" } server | 1.428 INFO [Server 4629e7ee9fc824e3dfff] ConnectionClose received. Error code: Transport(0) frame type 0 reason server | 1.428 DEBUG [Server 4629e7ee9fc824e3dfff] State change from Confirmed -> Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 370, tv_nsec: 479247429 } } server | 1.428 DEBUG [pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228] Path validated Instant { tv_sec: 370, tv_nsec: 255658119 } server | 1.428 DEBUG [Server 4629e7ee9fc824e3dfff] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false } server | 1.428 DEBUG Building Short dcid Some(CID [8]: a7f1c021b17425a7) server | 1.428 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 370, tv_nsec: 255658119 } server | 1.428 DEBUG [Server 4629e7ee9fc824e3dfff] pn=15 type=Short pri-path:a7f1c021b17425a7 [::]:443->[::ffff:193.167.0.100]:36228 Tos(Cs0, NotEct) len 35 server | TX -> Ack { largest_acknowledged: 14, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" } server | 1.428 DEBUG Setting timeout of 223.470126ms server | 1.428 DEBUG Setting timeout of 223.457873ms server | 1.459 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 370, tv_nsec: 479247429 } }; Total: 3 server | 1.459 DEBUG Setting timeout of 192.901094ms server | 1.459 DEBUG Setting timeout of 192.876598ms server | 1.653 DEBUG [Server 4629e7ee9fc824e3dfff] State change from Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 370, tv_nsec: 479247429 } } -> Closed(Transport(Peer(0))) server | 1.653 INFO Closing timer expired client | task finished, total task_req_cnt: 1, req_fin_cnt: 1, req_sent_cnt: 0, req_create_cnt: 1 client | all tasks are finished, will break loop and exit client | 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-09-11 19:39:28,186 Using the client's key log file. 2025-09-11 19:39:28,194 2025-09-11 19:39:28,194 Using the client's key log file. 2025-09-11 19:39:28,195 Using the client's key log file. 2025-09-11 19:39:28,202 2025-09-11 19:39:28,202 Using the client's key log file. 2025-09-11 19:39:28,598 Check of downloaded files succeeded. 2025-09-11 19:39:28,998 Check of Retry succeeded. Token used: 52657472790100d1c89ecec69b946b80f9368c57a6c326a7521568d6725e375bb1df43bd8ab5c15f1c61bbdd2a05779478597c