2025-04-30 12:31:17,250 Generated random file: idwrhclndk of size: 5120 2025-04-30 12:31:17,250 Generated random file: moxwzaohrd of size: 10240 2025-04-30 12:31:17,250 Requests: https://server6:443/idwrhclndk https://server6:443/moxwzaohrd 2025-04-30 12:31:17,309 2025-04-30 12:31:17,310 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_noz17xy3/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_ks4ay42u/ DOWNLOADS=/tmp/download_yq8yf5vq/ SERVER_LOGS=/tmp/logs_server_zizd0f6g CLIENT_LOGS=/tmp/logs_client_jsedofap SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=aiortc/aioquic-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/idwrhclndk https://server6:443/moxwzaohrd" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 12:31:29,809 Container sim Recreate Container sim Recreated Container server Recreate Container client 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-checksumming: off client | tx-checksum-ip-generic: off client | tx-checksum-sctp: off client | tcp-segmentation-offload: off client | tx-tcp-segmentation: off [requested on] client | tx-tcp-ecn-segmentation: off [requested on] client | tx-tcp-mangleid-segmentation: off [requested on] client | tx-tcp6-segmentation: off [requested on] client | tx-udp-segmentation: off [requested on] 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.kk2jRNuOQ7 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.kk2jRNuOQ7 server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.kk2jRNuOQ7 -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 | 4b:f7:4c:bb:82:a4:05:26:18:cb:34:12:c2:18:62:8b: server | fc:e5:e7:8d 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 12:31:17 2025 server | Not After : Sat May 10 12:31:17 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:05:1f:a2:c8:2d:cb:f4:13:e1:84:41:f1:af:c4:37: server | 22:e2:39:dc:a5:2e:2b:62:d3:dc:dc:95:d3:e9:96:06: server | d4:c8:f2:ee:48:14:ea:f0:0e:f5:47:75:32:cd:70:58: server | 1c:9b:db:d8:63:42:28:2b:01:22:13:88:13:9d:2d:de: server | db 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 | 79:39:f4:0d:a1:f1:2d:cc:72:fb:53:b0:46:21:5d:58: server | c0:3d:47:2a server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 7e:61:4a:9f:99:8b:c4:d1:dd:4b:a5:98:68:fd:8e:09: server | 40:18:30:c8 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:21:00:d0:47:ba:5c:34:41:87:99:d3:df:3e: server | 4b:16:07:94:67:a3:7d:3b:7f:de:dd:b1:8f:98:7f:f4: server | ab:aa:fd:70:5b:02:20:53:9f:66:36:8a:74:3d:55:87: server | 71:3e:19:8f:d7:e7:ac:89:bb:5d:a5:55:a7:7a:83:be: server | e1:75:54:10:45:96:c8 server | Fingerprint (SHA-256): server | D1:20:6B:C7:F6:FB:83:8F:AC:B5:68:60:57:4B:30:79:F4:E6:15:76:F2:82:99:41:0C:C9:F3:08:72:BC:1E:67 server | Fingerprint (SHA1): server | 93:6D:93:A9:F0:2A:3B:3A:6B:AD:80:CF:94:62:16:92:1F:91:94:54 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.784 DEBUG [Server] Unsupported version: 57414954 server | 0.784 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48675 IpTos(Cs0, NotEct) len 15 server | 0.784 DEBUG [Server] Unsupported version: 57414954 sim | server:443 is available after 1.03078587s server | 0.784 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48675 IpTos(Cs0, NotEct) len 15 server | 0.784 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.784 DEBUG [Server] Unsupported version: 57414954 server | 0.784 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48675 IpTos(Cs0, NotEct) len 15 server | 0.784 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: tcpdump: listening on eth1listening on eth0, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | , snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Starting client server | 1.163 DEBUG [Server] Handle initial server | 1.163 INFO AddressValidation: no token; accepting server | 1.163 INFO [Server] Accept connection CID [8]: 10bb7b95cbcecac4 server | 1.163 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.165 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500 server | 1.165 INFO [Server ...] Received valid Initial packet with scid CID [8]: 87c4a4d9ae646470 dcid CID [8]: 10bb7b95cbcecac4 server | 1.165 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=10bb7b95cbcecac4 server | 1.165 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.165 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.165 DEBUG [Server 10bb7b95cbcecac4] State change from Init -> WaitInitial server | 1.165 DEBUG [Server 10bb7b95cbcecac4] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 530 server | -> RX Crypto { offset: 0, len: 482 } server | 1.165 DEBUG Read Ok(482) bytes server | 1.165 DEBUG 0-RTT: no token, no 0-RTT server | 1.165 DEBUG Read secret available for Handshake: SymKey [32]: d821787f7ed9bc1bb81f3b1a7c1897cbe2b2ab112d9d1dd012f3d9c8413d07d8 server | 1.165 DEBUG Write secret available for Handshake: SymKey [32]: 099abb75b6ada992485c75e03a6b79904eef42a6eb0dbd23d0021e38cd1f1693 server | 1.165 DEBUG Writing transport parameters, msg=8 server | 1.166 DEBUG Read secret available for ApplicationData: SymKey [32]: 7b2bba2c83d032b31a66a1b5872963b7213c94483f3a6528a7fb1ad1d4e4b5c5 server | 1.166 DEBUG Write secret available for ApplicationData: SymKey [32]: ad58dbadbca31dd90e9c9bf29e775dfdb922f34f6ac8eb9eb32a22b8e6d3b8a9 server | 1.166 DEBUG [Agent 0x56111096c1d0] state -> InProgress server | 1.166 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.166 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.166 DEBUG [Crypto] Handshake keys installed server | 1.166 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.166 DEBUG [Crypto] Application write key installed server | 1.166 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 921, tv_nsec: 143599212 } server | 1.166 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:50883] Make permanent server | 1.166 DEBUG [unv-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883] set as primary path server | 1.166 DEBUG [Server 10bb7b95cbcecac4] State change from WaitInitial -> Handshaking server | 1.166 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 1.166 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.166 DEBUG Building Initial dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG CRYPTO for in offset=0, len=90 server | 1.166 DEBUG [Server 10bb7b95cbcecac4] pn=0 type=Initial pri-unv-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 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 | 1.166 DEBUG Building Handshake dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG CRYPTO for hs offset=0, len=724 server | 1.166 DEBUG [Server 10bb7b95cbcecac4] pn=0 type=Handshake pri-unv-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 916 server | TX -> Crypto { offset: 0, len: 724 } server | 1.166 DEBUG packet_sent this=0x56111096bb40, pn=0, ps=772 server | 1.166 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.166 DEBUG [Server 10bb7b95cbcecac4] pad Initial from 916 to PLPMTU 1232 server | 1.166 DEBUG packet_sent this=0x56111096bb40, pn=0, ps=460 server | 1.166 DEBUG ECN probing: sent 1 probes server | 1.166 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.166 DEBUG Building Initial dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG Building Handshake dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.166 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.166 DEBUG [Server 10bb7b95cbcecac4] delay duration 297.081235ms server | 1.166 DEBUG Setting timeout of 297.081235ms server | 1.166 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.166 DEBUG Building Initial dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG Building Handshake dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.166 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.166 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.166 DEBUG [Server 10bb7b95cbcecac4] delay duration 297.045809ms server | 1.166 DEBUG Setting timeout of 297.045809ms server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=1 type=Initial pri-unv-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 52 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 252, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=in, ranges=[0..=0] server | 1.201 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.201 DEBUG on_packets_acked this=0x56111096bb40, limited=1, bytes_in_flight=772, cwnd=12320, state=SlowStart, new_acked=460 server | 1.201 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.201 DEBUG [pri-unv-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883] Path validated Instant { tv_sec: 921, tv_nsec: 181383570 } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] Drop packet number space in server | 1.201 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=2 type=Handshake pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 91 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 252, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=hs, ranges=[0..=0] server | 1.201 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.201 DEBUG on_packets_acked this=0x56111096bb40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=772 server | 1.201 DEBUG Acked crypto frame space=hs offset=0 length=724 server | 1.201 DEBUG Read Ok(36) bytes server | 1.201 DEBUG [Agent 0x56111096c1d0] 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.201 DEBUG [Server 10bb7b95cbcecac4] TLS connection complete server | 1.201 DEBUG [pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883] Path validated Instant { tv_sec: 921, tv_nsec: 181383570 } server | 1.201 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.201 DEBUG [Crypto] application read keys installed server | 1.201 DEBUG [Server 10bb7b95cbcecac4] State change from Handshaking -> Connected server | 1.201 DEBUG [Server 10bb7b95cbcecac4] State change from Connected -> Confirmed server | 1.201 DEBUG PMTUD started with probe size 1380 server | 1.201 INFO [Server 10bb7b95cbcecac4] Connection established server | 1.201 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 921, tv_nsec: 181383570 } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=3 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1057 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [243, 131, 210, 169, 60, 134, 94, 157], stateless_reset_token: [149, 145, 111, 98, 216, 105, 46, 131, 8, 182, 89, 153, 151, 195, 14, 197] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [113, 180, 9, 185, 241, 188, 153, 43], stateless_reset_token: [198, 228, 189, 95, 9, 252, 14, 241, 178, 111, 205, 107, 152, 216, 189, 15] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [229, 109, 177, 210, 115, 117, 65, 246], stateless_reset_token: [100, 168, 45, 3, 31, 238, 34, 127, 110, 58, 15, 128, 97, 198, 179, 153] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [176, 193, 47, 187, 35, 218, 134, 203], stateless_reset_token: [111, 24, 176, 238, 115, 50, 129, 250, 189, 151, 159, 182, 153, 101, 94, 24] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [213, 242, 224, 144, 104, 22, 195, 173], stateless_reset_token: [27, 96, 188, 188, 42, 85, 90, 30, 130, 178, 116, 162, 180, 88, 10, 233] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [253, 91, 50, 180, 156, 61, 134, 254], stateless_reset_token: [244, 216, 185, 40, 10, 231, 207, 101, 176, 233, 117, 101, 6, 250, 3, 19] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [91, 67, 156, 57, 63, 20, 48, 78], stateless_reset_token: [120, 183, 137, 212, 146, 191, 156, 180, 71, 254, 81, 126, 165, 87, 152, 7] } server | -> RX Padding { len: 832 } server | 1.201 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 921, tv_nsec: 181383570 } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.201 DEBUG Building Handshake dcid Some(CID [8]: 87c4a4d9ae646470) scid Some(CID [10]: 02745f0b31921ea11b90) server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=1 type=Handshake pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 49 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.201 DEBUG [Server 10bb7b95cbcecac4] Drop packet number space hs server | 1.201 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.201 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=0 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1332 server | TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [174, 109, 75, 203, 87, 180, 88, 25, 181, 239], stateless_reset_token: [131, 34, 251, 47, 76, 196, 233, 20, 138, 51, 132, 74, 122, 243, 42, 241] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [20, 36, 29, 195, 208, 118, 237, 88, 94, 20], stateless_reset_token: [188, 225, 211, 163, 226, 120, 209, 254, 133, 58, 116, 152, 64, 79, 132, 251] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [37, 222, 203, 226, 66, 62, 16, 201, 190, 33], stateless_reset_token: [80, 95, 239, 63, 214, 89, 25, 202, 210, 126, 36, 143, 242, 211, 187, 42] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [108, 130, 48, 15, 113, 67, 211, 20, 180, 81], stateless_reset_token: [90, 232, 165, 117, 201, 70, 162, 74, 7, 40, 219, 175, 134, 247, 17, 82] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [93, 211, 71, 113, 92, 44, 5, 139, 232, 154], stateless_reset_token: [219, 23, 254, 140, 6, 184, 135, 123, 43, 188, 61, 37, 247, 134, 148, 113] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [122, 111, 210, 12, 217, 230, 5, 57, 168, 190], stateless_reset_token: [71, 105, 232, 27, 233, 214, 117, 212, 109, 175, 61, 29, 165, 95, 195, 155] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [24, 133, 195, 136, 136, 250, 152, 196, 156, 21], stateless_reset_token: [142, 224, 238, 131, 197, 82, 57, 238, 142, 221, 204, 157, 101, 176, 177, 178] } server | TX -> Padding { len: 1041 } server | 1.201 DEBUG packet_sent this=0x56111096bb40, pn=0, ps=1283 server | 1.201 DEBUG ECN probing: sent 2 probes server | 1.201 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.201 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.201 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.201 DEBUG [Server 10bb7b95cbcecac4] pn=1 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.201 DEBUG packet_sent this=0x56111096bb40, pn=1, ps=1332 server | 1.202 DEBUG ECN probing: sent 3 probes server | 1.202 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.202 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.405585ms server | 1.202 DEBUG Setting timeout of 1.405585ms server | 1.202 DEBUG [Server 10bb7b95cbcecac4] pn=4 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 50 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 1.202 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 921, tv_nsec: 202128427 } server | 1.202 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.202 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.377222ms server | 1.202 DEBUG Setting timeout of 1.377222ms server | 1.202 DEBUG [Server 10bb7b95cbcecac4] pn=5 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 50 server | -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true } server | 1.202 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 921, tv_nsec: 182176527 } server | 1.202 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.202 DEBUG [Server 10bb7b95cbcecac4] pn=2 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 31 server | TX -> Ack { largest_acknowledged: 5, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.202 DEBUG ECN probing: sent 4 probes server | 1.202 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.202 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.202 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.314597ms server | 1.202 DEBUG Setting timeout of 1.314597ms server | 1.203 DEBUG [Server 10bb7b95cbcecac4] send session ticket 4063000810bb7b95cbcecac40104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a02745f0b31921ea11b90110c000000019a3a7ada000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.203 DEBUG Path = 'idwrhclndk' server | 1.203 DEBUG Path = 'moxwzaohrd' server | 1.203 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.203 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.203 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.203 DEBUG [Server 10bb7b95cbcecac4] delay duration 171.829µs server | 1.203 DEBUG Setting timeout of 171.829µs server | 1.204 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.204 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.204 DEBUG [Server 10bb7b95cbcecac4] pn=3 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 1.204 DEBUG packet_sent this=0x56111096bb40, pn=3, ps=1232 server | 1.204 DEBUG ECN probing: sent 5 probes server | 1.204 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.204 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.204 DEBUG [Server 10bb7b95cbcecac4] pn=4 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 1.204 DEBUG packet_sent this=0x56111096bb40, pn=4, ps=1232 server | 1.204 DEBUG ECN probing: sent 6 probes server | 1.204 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.204 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.204 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.204 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.812928ms server | 1.204 DEBUG Setting timeout of 1.812928ms server | 1.204 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.204 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.204 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.204 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.791408ms server | 1.204 DEBUG Setting timeout of 1.791408ms server | 1.207 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.207 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.207 DEBUG [Server 10bb7b95cbcecac4] pn=5 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 1.207 DEBUG packet_sent this=0x56111096bb40, pn=5, ps=1232 server | 1.207 DEBUG ECN probing: sent 7 probes server | 1.207 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.207 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.207 DEBUG [Server 10bb7b95cbcecac4] pn=6 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false } server | 1.207 DEBUG packet_sent this=0x56111096bb40, pn=6, ps=1232 server | 1.207 DEBUG ECN probing: sent 8 probes server | 1.207 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.207 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.207 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.207 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.830908ms server | 1.207 DEBUG Setting timeout of 1.830908ms server | 1.207 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.207 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.207 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.207 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.803257ms server | 1.207 DEBUG Setting timeout of 1.803257ms server | 1.209 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.209 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.209 DEBUG [Server 10bb7b95cbcecac4] pn=7 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 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.209 DEBUG packet_sent this=0x56111096bb40, pn=7, ps=1232 server | 1.209 DEBUG ECN probing: sent 9 probes server | 1.210 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.210 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.210 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.210 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.554998ms server | 1.210 DEBUG Setting timeout of 1.554998ms server | 1.210 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.210 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.210 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.210 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.533388ms server | 1.210 DEBUG Setting timeout of 1.533388ms server | 1.212 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.212 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.212 DEBUG [Server 10bb7b95cbcecac4] pn=8 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 4, offset: 888, len: >>1202, fin: false } server | 1.212 DEBUG packet_sent this=0x56111096bb40, pn=8, ps=1232 server | 1.212 DEBUG ECN probing: sent 10 probes server | 1.212 DEBUG ECN probing concluded with 10 probes sent server | 1.212 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.212 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.212 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.212 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.280128ms server | 1.212 DEBUG Setting timeout of 1.280128ms server | 1.212 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.212 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.212 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.212 DEBUG [Server 10bb7b95cbcecac4] delay duration 1.261302ms server | 1.212 DEBUG Setting timeout of 1.261302ms server | 1.214 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.214 DEBUG [Server 10bb7b95cbcecac4] pn=9 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 4, offset: 2090, len: >>1202, fin: false } server | 1.214 DEBUG packet_sent this=0x56111096bb40, pn=9, ps=1232 server | 1.214 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1081, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.214 DEBUG [Server 10bb7b95cbcecac4] pn=10 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1081 server | TX -> Stream { stream_id: 4, offset: 3292, len: >>1051, fin: false } server | 1.214 DEBUG packet_sent this=0x56111096bb40, pn=10, ps=1081 server | 1.214 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.214 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG [Server 10bb7b95cbcecac4] delay duration 119.413535ms server | 1.214 DEBUG Setting timeout of 119.413535ms server | 1.214 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.214 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.214 DEBUG [Server 10bb7b95cbcecac4] delay duration 119.394671ms server | 1.214 DEBUG Setting timeout of 119.394671ms server | 1.234 DEBUG [Server 10bb7b95cbcecac4] pn=6 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.234 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=1] server | 1.234 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 1.234 WARN ECN validation failed, no ECN counts in ACK frame server | 1.234 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.234 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615 server | 1.234 DEBUG PMTUD probe of size 1380 succeeded server | 1.234 DEBUG PMTUD started with probe size 1420 server | 1.234 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.234 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.234 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.234 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.234 DEBUG [Server 10bb7b95cbcecac4] pn=11 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 4, offset: 4343, len: >>1341, fin: false } server | 1.234 DEBUG packet_sent this=0x56111096bb40, pn=11, ps=1372 server | 1.234 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.234 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.234 DEBUG [Server 10bb7b95cbcecac4] pn=12 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 5684, len: >>1302, fin: false } server | 1.234 DEBUG packet_sent this=0x56111096bb40, pn=12, ps=1332 server | 1.234 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.235 DEBUG [Server 10bb7b95cbcecac4] pn=13 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 6986, len: >>1302, fin: false } server | 1.235 DEBUG packet_sent this=0x56111096bb40, pn=13, ps=1332 server | 1.235 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1194, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.235 DEBUG [Server 10bb7b95cbcecac4] pn=14 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1194 server | TX -> Stream { stream_id: 4, offset: 8288, len: >>1164, fin: false } server | 1.235 DEBUG packet_sent this=0x56111096bb40, pn=14, ps=1194 server | 1.235 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.235 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG [Server 10bb7b95cbcecac4] delay duration 109.488117ms server | 1.235 DEBUG Setting timeout of 109.488117ms server | 1.235 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.235 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.235 DEBUG [Server 10bb7b95cbcecac4] delay duration 109.454064ms server | 1.235 DEBUG Setting timeout of 109.454064ms server | 1.237 DEBUG [Server 10bb7b95cbcecac4] pn=7 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 8, first_ack_range: 4, ack_ranges: [], ecn_count: None } server | 1.237 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=4] server | 1.237 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.237 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.237 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12471/17399 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=12471, cwnd=17399, state=SlowStart, new_acked=2464 server | 1.237 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.237 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.237 DEBUG CRYPTO for ap offset=0, len=305 server | 1.237 DEBUG [Server 10bb7b95cbcecac4] pn=15 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 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, 62, 30, 41, 146, 9, 127, 251, 73, 178, 129, 26, 65, 2, 247, 192, 167, 53, 93, 135, 201, 124, 220, 192, 87, 224, 225, 239, 231, 73, 12, 3, 153, 58, 214, 128, 22] } server | 1.237 DEBUG packet_sent this=0x56111096bb40, pn=15, ps=1174 server | 1.237 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.237 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.237 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.237 DEBUG [Server 10bb7b95cbcecac4] delay duration 101.6914ms server | 1.237 DEBUG Setting timeout of 101.6914ms server | 1.237 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.237 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.237 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.237 DEBUG [Server 10bb7b95cbcecac4] delay duration 101.665572ms server | 1.237 DEBUG Setting timeout of 101.665572ms server | 1.240 DEBUG [Server 10bb7b95cbcecac4] pn=8 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 7, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 1.240 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=6] server | 1.240 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.240 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.240 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11181/19863 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=11181, cwnd=19863, state=SlowStart, new_acked=2464 server | 1.240 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.240 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.240 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.240 DEBUG [Server 10bb7b95cbcecac4] delay duration 92.013164ms server | 1.240 DEBUG Setting timeout of 92.013164ms server | 1.240 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.240 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.240 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.240 DEBUG [Server 10bb7b95cbcecac4] delay duration 91.967549ms server | 1.240 DEBUG Setting timeout of 91.967549ms server | 1.242 DEBUG [Server 10bb7b95cbcecac4] pn=9 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 35 server | -> RX Ack { largest_acknowledged: 7, ack_delay: 186, first_ack_range: 7, ack_ranges: [], ecn_count: None } server | 1.242 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=7] server | 1.243 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=7 server | 1.243 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9949/21095 ssthresh 18446744073709551615] slow start += 1232 server | 1.243 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9949/21095 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=9949, cwnd=21095, state=SlowStart, new_acked=1232 server | 1.243 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.243 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.243 DEBUG [Server 10bb7b95cbcecac4] pn=16 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 28 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | 1.243 DEBUG packet_sent this=0x56111096bb40, pn=16, ps=29 server | 1.243 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.243 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.243 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.243 DEBUG [Server 10bb7b95cbcecac4] delay duration 89.289111ms server | 1.243 DEBUG Setting timeout of 89.289111ms server | 1.243 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.243 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.243 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.243 DEBUG [Server 10bb7b95cbcecac4] delay duration 89.258975ms server | 1.243 DEBUG Setting timeout of 89.258975ms server | 1.244 DEBUG [Server 10bb7b95cbcecac4] pn=10 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 35 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 148, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 1.244 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=8] server | 1.244 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.244 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8746/22327 ssthresh 18446744073709551615] slow start += 1232 server | 1.244 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8746/22327 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=8746, cwnd=22327, state=SlowStart, new_acked=1232 server | 1.244 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.244 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.244 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.244 DEBUG [Server 10bb7b95cbcecac4] delay duration 82.988978ms server | 1.244 DEBUG Setting timeout of 82.988978ms server | 1.244 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.244 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.244 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.244 DEBUG [Server 10bb7b95cbcecac4] delay duration 82.943954ms server | 1.244 DEBUG Setting timeout of 82.943954ms server | 1.246 DEBUG [Server 10bb7b95cbcecac4] pn=11 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 10, ack_delay: 13, first_ack_range: 10, ack_ranges: [], ecn_count: None } server | 1.246 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=10] server | 1.246 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10 server | 1.246 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6433/24640 ssthresh 18446744073709551615] slow start += 2313 server | 1.246 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6433/24640 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=6433, cwnd=24640, state=SlowStart, new_acked=2313 server | 1.246 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.246 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.246 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.246 DEBUG [Server 10bb7b95cbcecac4] delay duration 77.391395ms server | 1.246 DEBUG Setting timeout of 77.391395ms server | 1.246 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.246 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.246 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.246 DEBUG [Server 10bb7b95cbcecac4] delay duration 77.346992ms server | 1.246 DEBUG Setting timeout of 77.346992ms server | 1.267 DEBUG [Server 10bb7b95cbcecac4] pn=12 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 12, ack_delay: 7, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | 1.267 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=12] server | 1.267 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12 server | 1.267 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3729/27344 ssthresh 18446744073709551615] slow start += 2704 server | 1.267 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3729/27344 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=3729, cwnd=27344, state=SlowStart, new_acked=2704 server | 1.267 DEBUG PMTUD probe of size 1420 succeeded server | 1.267 DEBUG PMTUD started with probe size 1470 server | 1.267 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 1.267 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.267 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.267 DEBUG Sending PMTUD probe of size 1470, count 1 server | 1.267 DEBUG [Server 10bb7b95cbcecac4] pn=17 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 1422 server | TX -> Ping server | TX -> Padding { len: 1395 } server | 1.267 DEBUG packet_sent this=0x56111096bb40, pn=17, ps=1422 server | 1.267 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.267 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.267 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.267 DEBUG [Server 10bb7b95cbcecac4] delay duration 77.706947ms server | 1.267 DEBUG Setting timeout of 77.706947ms server | 1.267 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.267 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.267 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.267 DEBUG [Server 10bb7b95cbcecac4] delay duration 77.682071ms server | 1.267 DEBUG Setting timeout of 77.682071ms server | 1.269 DEBUG [Server 10bb7b95cbcecac4] pn=13 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 7, first_ack_range: 14, ack_ranges: [], ecn_count: None } server | 1.269 DEBUG [Server 10bb7b95cbcecac4] Rx ACK space=ap, ranges=[0..=14] server | 1.269 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14 server | 1.269 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2625/29870 ssthresh 18446744073709551615] slow start += 2526 server | 1.269 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2625/29870 ssthresh 18446744073709551615] on_packets_acked this=0x56111096bb40, limited=0, bytes_in_flight=2625, cwnd=29870, state=SlowStart, new_acked=2526 server | 1.269 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.269 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG [Server 10bb7b95cbcecac4] delay duration 71.254072ms server | 1.269 DEBUG Setting timeout of 71.254072ms server | 1.269 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.269 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG [Server 10bb7b95cbcecac4] delay duration 71.208757ms server | 1.269 DEBUG Setting timeout of 71.208757ms server | 1.271 DEBUG [Server 10bb7b95cbcecac4] pn=14 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 33 server | -> RX ConnectionClose { error_code: Application(256), frame_type: 0, reason_phrase: "" } server | 1.271 INFO [Server 10bb7b95cbcecac4] ConnectionClose received. Error code: Application(256) frame type 0 reason server | 1.271 DEBUG [Server 10bb7b95cbcecac4] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(256)), timeout: Instant { tv_sec: 921, tv_nsec: 471393998 } } server | 1.271 DEBUG [pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883] Path validated Instant { tv_sec: 921, tv_nsec: 251434241 } server | 1.271 DEBUG [Server 10bb7b95cbcecac4] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.271 DEBUG Building Short dcid Some(CID [8]: 87c4a4d9ae646470) server | 1.271 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 921, tv_nsec: 251434241 } server | 1.271 DEBUG [Server 10bb7b95cbcecac4] pn=18 type=Short pri-path:87c4a4d9ae646470 [::]:443->[fd00:cafe:cafe::100]:50883 IpTos(Cs0, NotEct) len 35 server | TX -> Ack { largest_acknowledged: 14, ack_delay: 0, first_ack_range: 11, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.271 DEBUG Setting timeout of 219.83231ms server | 1.271 DEBUG Setting timeout of 219.820698ms server | 1.492 DEBUG [Server 10bb7b95cbcecac4] State change from Draining { error: Transport(PeerApplicationError(256)), timeout: Instant { tv_sec: 921, tv_nsec: 471393998 } } -> Closed(Transport(PeerApplicationError(256))) server | 1.492 INFO Closing timer expired 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 12:31:29,902 Using the client's key log file. 2025-04-30 12:31:29,912 2025-04-30 12:31:29,912 Using the client's key log file. 2025-04-30 12:31:29,912 Using the client's key log file. 2025-04-30 12:31:29,921 2025-04-30 12:31:29,921 Using the client's key log file. 2025-04-30 12:31:30,490 Check of downloaded files succeeded. 2025-04-30 12:31:31,054 Check of downloaded files succeeded.