2025-04-30 12:37:12,482 Generated random file: ptwyizydzf of size: 5120 2025-04-30 12:37:12,482 Generated random file: egawwlsfhv of size: 10240 2025-04-30 12:37:12,482 Requests: https://server6:443/ptwyizydzf https://server6:443/egawwlsfhv 2025-04-30 12:37:12,545 2025-04-30 12:37:12,545 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_geqv6irt/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_z32ji9at/ DOWNLOADS=/tmp/download_1cnw22y9/ SERVER_LOGS=/tmp/logs_server_4hl52bc9 CLIENT_LOGS=/tmp/logs_client_4gtw1p9o SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=peterdoornbosch/kwik_n_flupke-interop SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/ptwyizydzf https://server6:443/egawwlsfhv" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 12:37:25,622 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-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 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.JZa9Ba8iBL 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.JZa9Ba8iBL server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.JZa9Ba8iBL -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 | 1d:db:a3:1e:ce:43:03:e7:ea:5d:09:68:28:c5:a2:9f: server | e4:14:5d:00 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:37:12 2025 server | Not After : Sat May 10 12:37:12 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:f1:b0:a8:b0:83:ef:0e:8c:61:81:76:fd:f9:a2:f9: server | 6e:3f:e9:d3:56:09:11:15:d6:9d:45:41:ae:94:8c:d5: server | 0f:86:c0:fd:87:4d:52:aa:a4:c0:3b:03:16:71:f2:77: server | a9:ca:d7:b0:70:fe:cb:9d:11:bd:79:f3:29:0a:4d:f1: server | 99 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 | 0f:47:5f:42:39:7e:63:81:89:f9:eb:cf:fb:a2:1e:5c: server | 7b:9a:6c:ff server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 65:9b:11:bd:cf:bf:a3:9a:06:68:2b:d7:0a:97:10:c0: server | 71:8d:c3:59 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:20:60:5e:bb:18:7d:12:b1:69:aa:96:04:eb: server | 92:84:4c:99:c7:be:46:e2:04:4c:55:1a:23:60:8c:3f: server | 8e:e8:b3:43:02:21:00:c6:eb:bb:ff:60:99:a3:dc:b1: server | eb:e0:40:a3:a3:cd:6f:ab:19:6d:41:3b:e3:3c:0a:80: server | 07:ee:5f:3d:e5:20:c6 server | Fingerprint (SHA-256): server | 6C:67:75:48:51:A6:75:C6:8B:62:A5:47:0D:D8:E4:18:C0:9C:65:49:9E:28:94:49:73:E1:49:B3:C4:34:65:FD server | Fingerprint (SHA1): server | 5D:46:51:B7:CB:DD:8B:6A:FB:63:D4:03:A2:91:5E:34:89:61:49:D5 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 client | Certificate was added to keystore client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | 0.783 DEBUG [Server] Unsupported version: 57414954 server | 0.783 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:55675 IpTos(Cs0, NotEct) len 15 server | 0.783 DEBUG [Server] Unsupported version: 57414954 server | 0.783 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:55675 IpTos(Cs0, NotEct) len 15 server | 0.783 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.783 DEBUG [Server] Unsupported version: 57414954 server | 0.783 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:55675 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.043728406s 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: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Writing keys to /logs/keys.log server | 1.855 DEBUG [Server] Handle initial server | 1.855 INFO AddressValidation: no token; accepting server | 1.855 INFO [Server] Accept connection CID [8]: 34b3962cb7d3987d server | 1.855 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.857 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500 server | 1.857 INFO [Server ...] Received valid Initial packet with scid CID [8]: a6d71ad3455a80b8 dcid CID [8]: 34b3962cb7d3987d server | 1.857 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=34b3962cb7d3987d server | 1.857 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.857 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.857 DEBUG [Server 34b3962cb7d3987d] State change from Init -> WaitInitial server | 1.857 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1200 server | -> RX Crypto { offset: 0, len: 257 } server | -> RX Padding { len: 896 } server | 1.857 DEBUG Read Ok(257) bytes server | 1.857 DEBUG 0-RTT: no token, no 0-RTT server | 1.858 DEBUG Read secret available for Handshake: SymKey [32]: 58b0a8ef1737ea2cec3c2db720731c42f4fef3cc03b60f8f7acaaee4ce729496 server | 1.858 DEBUG Write secret available for Handshake: SymKey [32]: 4f758f7ce3cbaa1e2ebfedec5b21579025622aec1f86041104ec3efde75bfa00 server | 1.858 DEBUG Writing transport parameters, msg=8 server | 1.858 DEBUG Read secret available for ApplicationData: SymKey [32]: 4dbfa6a11cd6b969dc5dfad09f9d03eace2c46138ce2431b003c545691733f58 server | 1.858 DEBUG Write secret available for ApplicationData: SymKey [32]: db30254af601164a9193cb89db22e05701ae7baa0a18ae3a7819a5b000bd8970 server | 1.858 DEBUG [Agent 0x55e964bbe1d0] state -> InProgress server | 1.858 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.858 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.858 DEBUG [Crypto] Handshake keys installed server | 1.858 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.858 DEBUG [Crypto] Application write key installed server | 1.859 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 793, tv_nsec: 461343912 } server | 1.859 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:33837] Make permanent server | 1.859 DEBUG [unv-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837] set as primary path server | 1.859 DEBUG [Server 34b3962cb7d3987d] State change from WaitInitial -> Handshaking server | 1.859 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.859 DEBUG Building Initial dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG CRYPTO for in offset=0, len=123 server | 1.859 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Initial pri-unv-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 177 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 123 } server | 1.859 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG CRYPTO for hs offset=0, len=718 server | 1.859 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Handshake pri-unv-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 943 server | TX -> Crypto { offset: 0, len: 718 } server | 1.859 DEBUG packet_sent this=0x55e964bbdb40, pn=0, ps=766 server | 1.859 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.859 DEBUG [Server 34b3962cb7d3987d] pad Initial from 943 to PLPMTU 1232 server | 1.859 DEBUG packet_sent this=0x55e964bbdb40, pn=0, ps=466 server | 1.859 DEBUG ECN probing: sent 1 probes server | 1.859 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.859 DEBUG Building Initial dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.859 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.859 DEBUG [Server 34b3962cb7d3987d] delay duration 296.59206ms server | 1.859 DEBUG Setting timeout of 296.59206ms server | 1.859 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.859 DEBUG Building Initial dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.859 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.859 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.859 DEBUG [Server 34b3962cb7d3987d] delay duration 296.560822ms server | 1.859 DEBUG Setting timeout of 296.560822ms server | 1.952 DEBUG [Server 34b3962cb7d3987d] pn=1 type=Initial pri-unv-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1201 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Padding { len: 1151 } server | 1.952 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=in, ranges=[0..=0] server | 1.952 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.952 DEBUG on_packets_acked this=0x55e964bbdb40, limited=1, bytes_in_flight=766, cwnd=12320, state=SlowStart, new_acked=466 server | 1.952 DEBUG Acked crypto frame space=in offset=0 length=123 server | 1.952 DEBUG [pri-unv-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837] Path validated Instant { tv_sec: 793, tv_nsec: 558206811 } server | 1.952 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.952 DEBUG Building Initial dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.952 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.952 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.952 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.952 DEBUG [Server 34b3962cb7d3987d] delay duration 193.725796ms server | 1.952 DEBUG Setting timeout of 193.725796ms server | 1.952 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.952 DEBUG Building Initial dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.952 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.952 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.952 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.952 DEBUG [Server 34b3962cb7d3987d] delay duration 193.580977ms server | 1.952 DEBUG Setting timeout of 193.580977ms server | 1.991 DEBUG [Server 34b3962cb7d3987d] Drop packet number space in server | 1.991 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.991 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Handshake pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 82 server | -> RX Crypto { offset: 0, len: 36 } server | 1.991 DEBUG Read Ok(36) bytes server | 1.991 DEBUG [Agent 0x55e964bbe1d0] 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.991 DEBUG [Server 34b3962cb7d3987d] TLS connection complete server | 1.991 DEBUG [pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837] Path validated Instant { tv_sec: 793, tv_nsec: 597157907 } server | 1.991 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.991 DEBUG [Crypto] application read keys installed server | 1.991 DEBUG [Server 34b3962cb7d3987d] State change from Handshaking -> Connected server | 1.991 DEBUG [Server 34b3962cb7d3987d] State change from Connected -> Confirmed server | 1.991 DEBUG PMTUD started with probe size 1380 server | 1.991 INFO [Server 34b3962cb7d3987d] Connection established server | 1.991 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 793, tv_nsec: 597157907 } server | 1.991 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.991 DEBUG Building Handshake dcid Some(CID [8]: a6d71ad3455a80b8) scid Some(CID [10]: 4556911b0475618ef5a5) server | 1.991 DEBUG [Server 34b3962cb7d3987d] pn=1 type=Handshake pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 49 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.991 DEBUG [Server 34b3962cb7d3987d] Drop packet number space hs server | 1.991 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.991 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.991 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [159, 45, 67, 51, 132, 76, 240, 75, 28, 107], stateless_reset_token: [67, 131, 202, 150, 159, 190, 104, 134, 222, 14, 20, 191, 58, 246, 132, 43] } server | TX -> Padding { len: 1226 } server | 1.991 DEBUG packet_sent this=0x55e964bbdb40, pn=0, ps=1283 server | 1.991 DEBUG ECN probing: sent 2 probes server | 1.991 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.991 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.991 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.992 DEBUG [Server 34b3962cb7d3987d] pn=1 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.992 DEBUG packet_sent this=0x55e964bbdb40, pn=1, ps=1332 server | 1.992 DEBUG ECN probing: sent 3 probes server | 1.992 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.992 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.992 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.992 DEBUG [Server 34b3962cb7d3987d] delay duration 4.79848ms server | 1.992 DEBUG Setting timeout of 4.79848ms server | 1.993 DEBUG [Server 34b3962cb7d3987d] send session ticket 4063000834b3962cb7d3987d0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a4556911b0475618ef5a5110c000000012a7acaca000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.994 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.995 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.995 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.995 DEBUG [Server 34b3962cb7d3987d] delay duration 2.199498ms server | 1.995 DEBUG Setting timeout of 2.199498ms server | 1.998 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 1.998 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.998 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.998 DEBUG CRYPTO for ap offset=0, len=305 server | 1.998 DEBUG [Server 34b3962cb7d3987d] pn=2 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 380 server | TX -> Crypto { offset: 0, len: 305 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 243, 211, 159, 123, 66, 240, 168, 237, 119, 222, 112, 102, 125, 87, 212, 70, 222, 2, 200, 179, 78, 176, 174, 234, 182, 139, 24, 136, 207, 191, 191, 24, 152, 232, 122, 165] } server | 1.998 DEBUG packet_sent this=0x55e964bbdb40, pn=2, ps=380 server | 1.998 DEBUG ECN probing: sent 4 probes server | 1.998 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.999 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.999 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.999 DEBUG [Server 34b3962cb7d3987d] delay duration 314.772755ms server | 1.999 DEBUG Setting timeout of 314.772755ms server | 1.999 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.999 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 1.999 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.999 DEBUG [Server 34b3962cb7d3987d] delay duration 314.119448ms server | 1.999 DEBUG Setting timeout of 314.119448ms server | 2.026 DEBUG [Server 34b3962cb7d3987d] pn=0 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 70 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true } server | 2.026 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 793, tv_nsec: 651899159 } server | 2.026 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.026 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.026 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.026 DEBUG [Server 34b3962cb7d3987d] delay duration 20ms server | 2.026 DEBUG Setting timeout of 20ms server | 2.026 DEBUG Path = 'ptwyizydzf' server | 2.026 DEBUG Path = 'egawwlsfhv' server | 2.026 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.026 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.026 DEBUG [Server 34b3962cb7d3987d] pn=3 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 2.026 DEBUG packet_sent this=0x55e964bbdb40, pn=3, ps=1232 server | 2.026 DEBUG ECN probing: sent 5 probes server | 2.026 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.026 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.026 DEBUG [Server 34b3962cb7d3987d] pn=4 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 2.026 DEBUG packet_sent this=0x55e964bbdb40, pn=4, ps=1232 server | 2.026 DEBUG ECN probing: sent 6 probes server | 2.026 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.027 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.027 DEBUG [Server 34b3962cb7d3987d] pn=5 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 2.027 DEBUG packet_sent this=0x55e964bbdb40, pn=5, ps=1232 server | 2.027 DEBUG ECN probing: sent 7 probes server | 2.027 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.027 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.027 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.027 DEBUG [Server 34b3962cb7d3987d] delay duration 4.313589ms server | 2.027 DEBUG Setting timeout of 4.313589ms server | 2.030 DEBUG [Server 34b3962cb7d3987d] pn=1 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 2.030 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[0..=1] server | 2.030 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 2.030 DEBUG on_packets_acked this=0x55e964bbdb40, limited=1, bytes_in_flight=4076, cwnd=12320, state=SlowStart, new_acked=2615 server | 2.030 DEBUG PMTUD probe of size 1380 succeeded server | 2.030 DEBUG PMTUD started with probe size 1420 server | 2.030 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 2.030 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.030 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.030 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.030 DEBUG [Server 34b3962cb7d3987d] delay duration 1.07757ms server | 2.030 DEBUG Setting timeout of 1.07757ms server | 2.030 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.030 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.030 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.030 DEBUG [Server 34b3962cb7d3987d] delay duration 1.002129ms server | 2.030 DEBUG Setting timeout of 1.002129ms server | 2.032 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.032 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.032 DEBUG Sending PMTUD probe of size 1420, count 1 server | 2.032 DEBUG [Server 34b3962cb7d3987d] pn=6 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1341, fin: false } server | 2.032 DEBUG packet_sent this=0x55e964bbdb40, pn=6, ps=1372 server | 2.032 DEBUG ECN probing: sent 8 probes server | 2.032 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.032 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.032 DEBUG [Server 34b3962cb7d3987d] delay duration 3.830318ms server | 2.032 DEBUG Setting timeout of 3.830318ms server | 2.032 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.032 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.032 DEBUG [Server 34b3962cb7d3987d] delay duration 3.809629ms server | 2.032 DEBUG Setting timeout of 3.809629ms server | 2.037 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.037 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.037 DEBUG [Server 34b3962cb7d3987d] pn=7 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1332 server | TX -> Stream { stream_id: 0, offset: 4949, len: 171, fin: true } server | TX -> Stream { stream_id: 4, offset: 0, len: >>1127, fin: false } server | 2.037 DEBUG packet_sent this=0x55e964bbdb40, pn=7, ps=1332 server | 2.037 DEBUG ECN probing: sent 9 probes server | 2.037 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.037 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.037 DEBUG [Server 34b3962cb7d3987d] delay duration 3.432105ms server | 2.037 DEBUG Setting timeout of 3.432105ms server | 2.037 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.037 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.037 DEBUG [Server 34b3962cb7d3987d] delay duration 3.408361ms server | 2.037 DEBUG Setting timeout of 3.408361ms server | 2.042 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.042 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.042 DEBUG [Server 34b3962cb7d3987d] pn=8 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, Ect0) len 1332 server | TX -> Stream { stream_id: 4, offset: 1127, len: >>1302, fin: false } server | 2.042 DEBUG packet_sent this=0x55e964bbdb40, pn=8, ps=1332 server | 2.042 DEBUG ECN probing: sent 10 probes server | 2.042 DEBUG ECN probing concluded with 10 probes sent server | 2.042 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.042 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.042 DEBUG [Server 34b3962cb7d3987d] delay duration 4.092448ms server | 2.042 DEBUG Setting timeout of 4.092448ms server | 2.042 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.042 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.042 DEBUG [Server 34b3962cb7d3987d] delay duration 4.067722ms server | 2.042 DEBUG Setting timeout of 4.067722ms server | 2.047 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.047 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.047 DEBUG [Server 34b3962cb7d3987d] pn=9 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1332 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 2097, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | TX -> Stream { stream_id: 4, offset: 2429, len: >>1296, fin: false } server | 2.047 DEBUG packet_sent this=0x55e964bbdb40, pn=9, ps=1332 server | 2.047 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.047 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.047 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.047 DEBUG [Server 34b3962cb7d3987d] delay duration 3.698814ms server | 2.047 DEBUG Setting timeout of 3.698814ms server | 2.047 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.047 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.047 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.047 DEBUG [Server 34b3962cb7d3987d] delay duration 3.673907ms server | 2.047 DEBUG Setting timeout of 3.673907ms server | 2.051 DEBUG [Server 34b3962cb7d3987d] pn=2 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 2375, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 2.051 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[0..=2] server | 2.051 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 2.051 WARN ECN validation failed, no ECN counts in ACK frame server | 2.051 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9064/12700 ssthresh 18446744073709551615] slow start += 380 server | 2.051 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9064/12700 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=9064, cwnd=12700, state=SlowStart, new_acked=380 server | 2.051 DEBUG Acked crypto frame space=ap offset=0 length=305 server | 2.051 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.051 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.051 DEBUG [Server 34b3962cb7d3987d] pn=10 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 3725, len: >>1302, fin: false } server | 2.051 DEBUG packet_sent this=0x55e964bbdb40, pn=10, ps=1332 server | 2.051 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.052 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.052 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.052 DEBUG [Server 34b3962cb7d3987d] delay duration 3.221227ms server | 2.052 DEBUG Setting timeout of 3.221227ms server | 2.052 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.052 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.052 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.052 DEBUG [Server 34b3962cb7d3987d] delay duration 3.199366ms server | 2.052 DEBUG Setting timeout of 3.199366ms server | 2.056 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.056 DEBUG [Server 34b3962cb7d3987d] pn=11 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 5027, len: >>1302, fin: false } server | 2.056 DEBUG packet_sent this=0x55e964bbdb40, pn=11, ps=1332 server | 2.056 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 972, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.056 DEBUG [Server 34b3962cb7d3987d] pn=12 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 972 server | TX -> Stream { stream_id: 4, offset: 6329, len: >>942, fin: false } server | 2.056 DEBUG packet_sent this=0x55e964bbdb40, pn=12, ps=972 server | 2.056 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG [Server 34b3962cb7d3987d] delay duration 298.645021ms server | 2.056 DEBUG Setting timeout of 298.645021ms server | 2.056 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.056 DEBUG [Server 34b3962cb7d3987d] delay duration 298.626607ms server | 2.056 DEBUG Setting timeout of 298.626607ms server | 2.060 DEBUG [Server 34b3962cb7d3987d] pn=3 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: None } server | 2.060 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[0..=4] server | 2.060 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 2.060 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10236/15164 ssthresh 18446744073709551615] slow start += 2464 server | 2.060 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10236/15164 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=10236, cwnd=15164, state=SlowStart, new_acked=2464 server | 2.060 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.060 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.060 DEBUG [Server 34b3962cb7d3987d] pn=13 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 7271, len: >>1302, fin: false } server | 2.060 DEBUG packet_sent this=0x55e964bbdb40, pn=13, ps=1332 server | 2.060 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.060 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.060 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.060 DEBUG [Server 34b3962cb7d3987d] delay duration 2.686289ms server | 2.060 DEBUG Setting timeout of 2.686289ms server | 2.060 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.060 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.060 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.060 DEBUG [Server 34b3962cb7d3987d] delay duration 2.658377ms server | 2.060 DEBUG Setting timeout of 2.658377ms server | 2.064 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 2.064 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.064 DEBUG [Server 34b3962cb7d3987d] pn=14 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 8573, len: >>1302, fin: false } server | 2.064 DEBUG packet_sent this=0x55e964bbdb40, pn=14, ps=1332 server | 2.064 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.064 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.064 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.064 DEBUG [Server 34b3962cb7d3987d] delay duration 1.94551ms server | 2.064 DEBUG Setting timeout of 1.94551ms server | 2.064 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.064 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.064 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.064 DEBUG [Server 34b3962cb7d3987d] delay duration 1.929019ms server | 2.064 DEBUG Setting timeout of 1.929019ms server | 2.064 DEBUG [Server 34b3962cb7d3987d] pn=4 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 375, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 2.064 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[0..=6] server | 2.064 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 2.064 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10296/17768 ssthresh 18446744073709551615] slow start += 2604 server | 2.064 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10296/17768 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=10296, cwnd=17768, state=SlowStart, new_acked=2604 server | 2.064 DEBUG PMTUD probe of size 1420 succeeded server | 2.064 DEBUG PMTUD started with probe size 1470 server | 2.064 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 2.064 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.064 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.064 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.065 DEBUG [Server 34b3962cb7d3987d] delay duration 1.291279ms server | 2.065 DEBUG Setting timeout of 1.291279ms server | 2.065 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.065 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.065 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.065 DEBUG [Server 34b3962cb7d3987d] delay duration 1.213634ms server | 2.065 DEBUG Setting timeout of 1.213634ms server | 2.067 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.067 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.067 DEBUG Sending PMTUD probe of size 1470, count 1 server | 2.067 DEBUG [Server 34b3962cb7d3987d] pn=15 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1422 server | TX -> Ping server | TX -> Stream { stream_id: 4, offset: 9875, len: 365, fin: true } server | TX -> Padding { len: 1024 } server | 2.067 DEBUG packet_sent this=0x55e964bbdb40, pn=15, ps=1422 server | 2.067 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.067 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.067 DEBUG [Server 34b3962cb7d3987d] delay duration 1.965668ms server | 2.067 DEBUG Setting timeout of 1.965668ms server | 2.067 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.067 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 2.067 DEBUG [Server 34b3962cb7d3987d] delay duration 1.95088ms server | 2.067 DEBUG Setting timeout of 1.95088ms server | 2.070 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.070 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.070 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.070 DEBUG [Server 34b3962cb7d3987d] delay duration 285.782192ms server | 2.070 DEBUG Setting timeout of 285.782192ms server | 2.070 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.070 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.070 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.070 DEBUG [Server 34b3962cb7d3987d] delay duration 285.758978ms server | 2.070 DEBUG Setting timeout of 285.758978ms server | 2.074 DEBUG [Server 34b3962cb7d3987d] pn=5 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 500, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 2.074 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[0..=8] server | 2.074 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 2.074 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9054/20432 ssthresh 18446744073709551615] slow start += 2664 server | 2.074 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9054/20432 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=9054, cwnd=20432, state=SlowStart, new_acked=2664 server | 2.074 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.074 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.074 DEBUG [Server 34b3962cb7d3987d] pn=16 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 28 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | 2.074 DEBUG packet_sent this=0x55e964bbdb40, pn=16, ps=29 server | 2.074 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.074 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.074 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.074 DEBUG [Server 34b3962cb7d3987d] delay duration 276.463922ms server | 2.074 DEBUG Setting timeout of 276.463922ms server | 2.074 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.074 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.074 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.074 DEBUG [Server 34b3962cb7d3987d] delay duration 276.437613ms server | 2.074 DEBUG Setting timeout of 276.437613ms server | 2.084 DEBUG [Server 34b3962cb7d3987d] pn=6 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 10, ack_delay: 375, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 2.084 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[2..=10] server | 2.084 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10 server | 2.084 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6419/23096 ssthresh 18446744073709551615] slow start += 2664 server | 2.084 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6419/23096 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=6419, cwnd=23096, state=SlowStart, new_acked=2664 server | 2.084 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.084 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.084 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.084 DEBUG [Server 34b3962cb7d3987d] delay duration 251.995975ms server | 2.084 DEBUG Setting timeout of 251.995975ms server | 2.084 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.084 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.084 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.084 DEBUG [Server 34b3962cb7d3987d] delay duration 251.888946ms server | 2.084 DEBUG Setting timeout of 251.888946ms server | 2.089 DEBUG [Server 34b3962cb7d3987d] pn=7 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 12, ack_delay: 0, first_ack_range: 10, ack_ranges: [], ecn_count: None } server | 2.089 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[2..=12] server | 2.089 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12 server | 2.089 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4115/25400 ssthresh 18446744073709551615] slow start += 2304 server | 2.089 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4115/25400 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=4115, cwnd=25400, state=SlowStart, new_acked=2304 server | 2.089 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.089 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.089 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.089 DEBUG [Server 34b3962cb7d3987d] delay duration 230.340255ms server | 2.089 DEBUG Setting timeout of 230.340255ms server | 2.089 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.089 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.089 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.089 DEBUG [Server 34b3962cb7d3987d] delay duration 230.270956ms server | 2.089 DEBUG Setting timeout of 230.270956ms server | 2.096 DEBUG [Server 34b3962cb7d3987d] pn=8 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 500, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | 2.096 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[2..=14] server | 2.096 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14 server | 2.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/28064 ssthresh 18446744073709551615] slow start += 2664 server | 2.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/28064 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=1451, cwnd=28064, state=SlowStart, new_acked=2664 server | 2.096 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.096 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.096 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.096 DEBUG [Server 34b3962cb7d3987d] delay duration 206.245812ms server | 2.096 DEBUG Setting timeout of 206.245812ms server | 2.096 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.096 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.096 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 2.096 DEBUG [Server 34b3962cb7d3987d] delay duration 206.160272ms server | 2.096 DEBUG Setting timeout of 206.160272ms server | 2.105 DEBUG [Server 34b3962cb7d3987d] pn=9 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 16, ack_delay: 750, first_ack_range: 14, ack_ranges: [], ecn_count: None } server | 2.105 DEBUG [Server 34b3962cb7d3987d] Rx ACK space=ap, ranges=[2..=16] server | 2.105 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=16 server | 2.105 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/29515 ssthresh 18446744073709551615] slow start += 1451 server | 2.105 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/29515 ssthresh 18446744073709551615] on_packets_acked this=0x55e964bbdb40, limited=0, bytes_in_flight=0, cwnd=29515, state=SlowStart, new_acked=1451 server | 2.105 DEBUG PMTUD probe of size 1470 succeeded server | 2.105 DEBUG PMTUD started with probe size 1500 server | 2.105 DEBUG PLPMTU changed from 1372 to 1422, updating pacer server | 2.105 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 2.105 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.105 DEBUG Sending PMTUD probe of size 1500, count 1 server | 2.105 DEBUG [Server 34b3962cb7d3987d] pn=17 type=Short pri-path:a6d71ad3455a80b8 [::]:443->[fd00:cafe:cafe::100]:33837 IpTos(Cs0, NotEct) len 1452 server | TX -> Ping server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 18 } server | TX -> Padding { len: 1423 } server | 2.105 DEBUG packet_sent this=0x55e964bbdb40, pn=17, ps=1452 server | 2.105 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 2.105 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.105 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 2.105 DEBUG [Server 34b3962cb7d3987d] delay duration 213.311944ms server | 2.106 DEBUG Setting timeout of 213.311944ms server | 2.106 DEBUG [Server 34b3962cb7d3987d] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 2.106 DEBUG Building Short dcid Some(CID [8]: a6d71ad3455a80b8) server | 2.106 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false } server | 2.106 DEBUG [Server 34b3962cb7d3987d] delay duration 213.285455ms server | 2.106 DEBUG Setting timeout of 213.285455ms client exited with code 0 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 12:37:25,733 Using the client's key log file. 2025-04-30 12:37:25,745 2025-04-30 12:37:25,746 Using the client's key log file. 2025-04-30 12:37:25,746 Using the client's key log file. 2025-04-30 12:37:25,756 2025-04-30 12:37:25,757 Using the client's key log file. 2025-04-30 12:37:26,333 Check of downloaded files succeeded. 2025-04-30 12:37:26,924 Check of downloaded files succeeded.