2025-04-30 10:36:21,397 Generated random file: zmfgmcoevk of size: 5120 2025-04-30 10:36:21,397 Generated random file: jbrxjcplhv of size: 10240 2025-04-30 10:36:21,397 Requests: https://server6:443/zmfgmcoevk https://server6:443/jbrxjcplhv 2025-04-30 10:36:21,456 2025-04-30 10:36:21,457 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_tqvpdfne/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_0iiqvnj1/ DOWNLOADS=/tmp/download_7ugfz__q/ SERVER_LOGS=/tmp/logs_server_nynb500t CLIENT_LOGS=/tmp/logs_client_fptxz292 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=cloudflare/quiche-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/zmfgmcoevk https://server6:443/jbrxjcplhv" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 10:36:33,811 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Setting up routes... 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 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 server | + P12CERT=/tmp/tmp.7TAYcjH2Cz server | + mkdir -p /neqo/db client | Endpoint's IPv4 address is 193.167.0.100 server | + certutil -N -d sql:/neqo/db --empty-password client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | supported server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.7TAYcjH2Cz server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.7TAYcjH2Cz -W '' client | wait-for-it: waiting 30 seconds for sim:57832 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 | 5c:2d:0f:74:b4:f6:47:98:09:93:73:0f:93:e0:23:dd: server | e6:16:84:fb 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 10:36:21 2025 server | Not After : Sat May 10 10:36:21 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:8b:1a:7a:5a:b0:da:9b:a7:00:b8:01:06:cb:d3:20: server | 04:78:a5:e2:fc:2a:9b:d4:34:68:3f:09:53:cd:c1:af: server | d5:d0:dc:b1:db:42:fe:d0:dc:1a:ef:5d:bc:8b:d8:2d: server | c6:53:8b:27:1d:da:e8:7a:2a:f2:b3:59:fd:f5:e3:83: server | f2 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 | f0:ec:87:52:8b:e8:82:87:6a:f8:8c:cc:e3:00:96:ad: server | b9:10:42:b5 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | a0:50:44:a7:c7:34:5c:44:0d:c7:1d:91:05:bc:8e:f9: server | 17:cf:ae:96 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:d0:77:29:b6:f4:b9:1d:9a:f9:c0:ac: server | 68:b4:aa:18:b0:a8:e4:49:17:1e:57:b9:28:bd:1c:f4: server | 63:52:93:bd:b4:02:21:00:f1:fb:11:a6:26:84:8d:e6: server | 4f:f3:c0:e3:eb:46:a2:5e:1c:db:b0:a6:a1:f2:d9:47: server | 7c:98:82:98:2a:60:02:e8 server | Fingerprint (SHA-256): server | 0B:58:94:75:65:BB:40:7B:24:45:07:70:50:FC:A3:C5:49:85:D6:E6:B4:75:BC:CC:0A:87:38:74:A2:AB:BC:EA server | Fingerprint (SHA1): server | B4:37:D7:77:BA:46:C5:D9:4B:0B:70:0C:9C:03:7A:4A:8C:FA:6C:DF 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.774 DEBUG [Server] Unsupported version: 57414954 server | 0.774 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48692 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.01610065s server | 0.775 DEBUG [Server] Unsupported version: 57414954 server | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48692 IpTos(Cs0, NotEct) len 15 server | 0.775 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.775 DEBUG [Server] Unsupported version: 57414954 server | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48692 IpTos(Cs0, NotEct) len 15 server | 0.775 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: sim:57832 is available after 1 seconds client | ## Starting quiche client... client | ## Client params: client | ## Requests: https://server6:443/zmfgmcoevk https://server6:443/jbrxjcplhv client | ## Test case: transfer server | 1.014 DEBUG [Server] Handle initial server | 1.014 INFO AddressValidation: no token; accepting server | 1.014 INFO [Server] Accept connection CID [16]: 811c23116aab6ccf54ab08473dfc55f3 server | 1.014 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.016 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500 server | 1.016 INFO [Server ...] Received valid Initial packet with scid CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd dcid CID [16]: 811c23116aab6ccf54ab08473dfc55f3 server | 1.016 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=811c23116aab6ccf54ab08473dfc55f3 server | 1.016 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.016 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.016 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from Init -> WaitInitial server | 1.016 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 333 server | -> RX Crypto { offset: 0, len: 266 } server | 1.016 DEBUG Read Ok(266) bytes server | 1.016 DEBUG 0-RTT: no token, no 0-RTT server | 1.017 DEBUG Read secret available for Handshake: SymKey [32]: e94f1e7186760ef2c1a4c76fd0504ea299717e4c1f5d35aad2fd9a7f6dad00d2 server | 1.017 DEBUG Write secret available for Handshake: SymKey [32]: 045ebaf69f03dec300a67b972a813a08f0d6ebd6ab97946b194cbe6b4656c7ed server | 1.017 DEBUG Writing transport parameters, msg=8 server | 1.017 DEBUG Read secret available for ApplicationData: SymKey [32]: da537bb14c1bbf782025f89da945462a885c610d48afbd17dd6cb943ecd70c13 server | 1.017 DEBUG Write secret available for ApplicationData: SymKey [32]: 1304fd91ebbc7013f100ca29d8d53e7ba33c3bee0d4b346070d52d62db769ee4 server | 1.017 DEBUG [Agent 0x56275e0ce1d0] state -> InProgress server | 1.017 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.017 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.017 DEBUG [Crypto] Handshake keys installed server | 1.017 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.017 DEBUG [Crypto] Application write key installed server | 1.017 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 815, tv_nsec: 252144651 } server | 1.017 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:35280] Make permanent server | 1.017 DEBUG [unv-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280] set as primary path server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from WaitInitial -> Handshaking server | 1.017 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.017 DEBUG Building Initial dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG CRYPTO for in offset=0, len=90 server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=0 type=Initial pri-unv-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 156 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.017 DEBUG Building Handshake dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG CRYPTO for hs offset=0, len=731 server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=0 type=Handshake pri-unv-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 947 server | TX -> Crypto { offset: 0, len: 731 } server | 1.017 DEBUG packet_sent this=0x56275e0cdb40, pn=0, ps=791 server | 1.017 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pad Initial from 947 to PLPMTU 1232 server | 1.017 DEBUG packet_sent this=0x56275e0cdb40, pn=0, ps=441 server | 1.017 DEBUG ECN probing: sent 1 probes server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.017 DEBUG Building Initial dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG Building Handshake dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.017 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 296.997065ms server | 1.017 DEBUG Setting timeout of 296.997065ms server | 1.017 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.017 DEBUG Building Initial dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG Building Handshake dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.017 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.017 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.018 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 296.964595ms server | 1.018 DEBUG Setting timeout of 296.964595ms server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=1 type=Initial pri-unv-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 63 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 71, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=in, ranges=[0..=0] server | 1.051 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.051 DEBUG on_packets_acked this=0x56275e0cdb40, limited=1, bytes_in_flight=791, cwnd=12320, state=SlowStart, new_acked=441 server | 1.051 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.051 DEBUG [pri-unv-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280] Path validated Instant { tv_sec: 815, tv_nsec: 288447231 } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Drop packet number space in server | 1.051 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=2 type=Handshake pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 101 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 55, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=hs, ranges=[0..=0] server | 1.051 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.051 DEBUG on_packets_acked this=0x56275e0cdb40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=791 server | 1.051 DEBUG Acked crypto frame space=hs offset=0 length=731 server | 1.051 DEBUG Read Ok(36) bytes server | 1.051 DEBUG [Agent 0x56275e0ce1d0] 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.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] TLS connection complete server | 1.051 DEBUG [pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280] Path validated Instant { tv_sec: 815, tv_nsec: 288447231 } server | 1.051 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.051 DEBUG [Crypto] application read keys installed server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from Handshaking -> Connected server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from Connected -> Confirmed server | 1.051 DEBUG PMTUD started with probe size 1380 server | 1.051 INFO [Server 811c23116aab6ccf54ab08473dfc55f3] Connection established server | 1.051 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 815, tv_nsec: 288447231 } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=3 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1186 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [218, 179, 238, 219, 221, 54, 69, 165, 28, 33, 56, 186, 179, 236, 235, 44, 216, 68, 52, 105], stateless_reset_token: [1, 3, 190, 126, 212, 78, 230, 202, 201, 151, 242, 252, 178, 95, 49, 104] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [143, 113, 158, 14, 82, 77, 143, 224, 18, 184, 159, 112, 137, 187, 103, 134, 156, 88, 141, 87], stateless_reset_token: [81, 179, 244, 184, 224, 102, 245, 89, 79, 209, 204, 89, 219, 50, 193, 183] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [95, 226, 87, 2, 125, 2, 34, 102, 231, 113, 203, 5, 199, 235, 234, 97, 97, 183, 41, 77], stateless_reset_token: [186, 67, 43, 37, 134, 115, 37, 223, 127, 207, 92, 35, 151, 139, 8, 207] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [197, 198, 245, 112, 54, 14, 98, 151, 58, 131, 84, 125, 53, 24, 249, 50, 211, 62, 93, 6], stateless_reset_token: [36, 146, 109, 98, 59, 72, 11, 39, 154, 62, 165, 220, 223, 147, 90, 220] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [228, 197, 33, 203, 216, 44, 204, 46, 112, 87, 139, 15, 61, 164, 228, 26, 33, 117, 118, 135], stateless_reset_token: [142, 233, 176, 133, 48, 12, 153, 40, 111, 75, 92, 136, 105, 136, 126, 229] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [15, 66, 144, 202, 231, 83, 177, 114, 246, 117, 116, 124, 19, 220, 84, 54, 11, 86, 224, 108], stateless_reset_token: [217, 242, 161, 231, 198, 140, 110, 74, 83, 53, 142, 193, 97, 235, 240, 211] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [49, 61, 99, 208, 187, 49, 33, 64, 8, 5, 248, 198, 200, 139, 9, 58, 115, 253, 42, 167], stateless_reset_token: [181, 229, 112, 97, 78, 23, 121, 59, 195, 25, 118, 51, 54, 85, 193, 107] } server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Padding { len: 856 } server | 1.051 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 815, tv_nsec: 288447231 } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.051 DEBUG Building Handshake dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) scid Some(CID [10]: 1522adf0d5c9bdb1905b) server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=1 type=Handshake pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 61 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Drop packet number space hs server | 1.051 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.051 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=0 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 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: [3, 98, 239, 169, 18, 137, 125, 113, 235, 138], stateless_reset_token: [247, 73, 70, 97, 78, 21, 225, 114, 49, 207, 35, 234, 146, 247, 65, 227] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [99, 141, 38, 17, 100, 243, 166, 31, 24, 137], stateless_reset_token: [72, 213, 197, 166, 130, 231, 22, 179, 205, 86, 41, 198, 39, 0, 5, 135] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [219, 243, 255, 213, 182, 95, 165, 21, 193, 242], stateless_reset_token: [43, 193, 88, 27, 188, 177, 44, 134, 156, 135, 57, 65, 209, 117, 201, 101] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [244, 232, 248, 172, 84, 170, 63, 29, 90, 213], stateless_reset_token: [77, 145, 14, 69, 126, 52, 23, 217, 69, 217, 208, 168, 188, 138, 127, 102] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [94, 232, 110, 151, 21, 141, 9, 116, 7, 40], stateless_reset_token: [188, 80, 93, 10, 50, 178, 142, 215, 53, 193, 203, 107, 37, 3, 249, 253] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [23, 69, 196, 162, 250, 147, 96, 42, 11, 45], stateless_reset_token: [198, 54, 209, 19, 130, 70, 205, 157, 205, 84, 19, 111, 206, 36, 227, 24] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [172, 9, 173, 156, 38, 248, 119, 237, 138, 113], stateless_reset_token: [243, 68, 178, 27, 82, 147, 225, 183, 110, 212, 35, 166, 32, 146, 11, 59] } server | TX -> Padding { len: 1017 } server | 1.051 DEBUG packet_sent this=0x56275e0cdb40, pn=0, ps=1271 server | 1.051 DEBUG ECN probing: sent 2 probes server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.051 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.051 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=1 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1293 } server | 1.051 DEBUG packet_sent this=0x56275e0cdb40, pn=1, ps=1332 server | 1.051 DEBUG ECN probing: sent 3 probes server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.051 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.051 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.329491ms server | 1.051 DEBUG Setting timeout of 1.329491ms server | 1.051 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=4 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 50 server | -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true } server | 1.051 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 815, tv_nsec: 309169760 } server | 1.052 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.052 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.052 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.052 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.298322ms server | 1.052 DEBUG Setting timeout of 1.298322ms server | 1.052 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] send session ticket 406b0010811c23116aab6ccf54ab08473dfc55f30104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a1522adf0d5c9bdb1905b110c000000018a0a8a6a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.052 DEBUG Path = 'zmfgmcoevk' server | 1.053 DEBUG Path = 'jbrxjcplhv' server | 1.053 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.053 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 217.345µs server | 1.053 DEBUG Setting timeout of 217.345µs server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.054 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=2 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1192, fin: false } server | 1.054 DEBUG packet_sent this=0x56275e0cdb40, pn=2, ps=1232 server | 1.054 DEBUG ECN probing: sent 4 probes server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.054 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=3 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1192, len: >>1190, fin: false } server | 1.054 DEBUG packet_sent this=0x56275e0cdb40, pn=3, ps=1232 server | 1.054 DEBUG ECN probing: sent 5 probes server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.054 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.054 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.747814ms server | 1.054 DEBUG Setting timeout of 1.747814ms server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.054 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.054 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.054 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.723168ms server | 1.054 DEBUG Setting timeout of 1.723168ms server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.057 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=4 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2382, len: >>1190, fin: false } server | 1.057 DEBUG packet_sent this=0x56275e0cdb40, pn=4, ps=1232 server | 1.057 DEBUG ECN probing: sent 6 probes server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.057 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=5 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3572, len: >>1190, fin: false } server | 1.057 DEBUG packet_sent this=0x56275e0cdb40, pn=5, ps=1232 server | 1.057 DEBUG ECN probing: sent 7 probes server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.057 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.057 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.760788ms server | 1.057 DEBUG Setting timeout of 1.760788ms server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.057 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.057 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.057 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.738466ms server | 1.057 DEBUG Setting timeout of 1.738466ms server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=6 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4762, len: 358, fin: true } server | TX -> Stream { stream_id: 4, offset: 0, len: >>828, fin: false } server | 1.060 DEBUG packet_sent this=0x56275e0cdb40, pn=6, ps=1232 server | 1.060 DEBUG ECN probing: sent 8 probes server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=7 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 4, offset: 828, len: >>1190, fin: false } server | 1.060 DEBUG packet_sent this=0x56275e0cdb40, pn=7, ps=1232 server | 1.060 DEBUG ECN probing: sent 9 probes server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.060 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.743656ms server | 1.060 DEBUG Setting timeout of 1.743656ms server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.060 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.060 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 1.725502ms server | 1.060 DEBUG Setting timeout of 1.725502ms server | 1.063 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.063 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.063 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=8 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 4, offset: 2018, len: >>1190, fin: false } server | 1.063 DEBUG packet_sent this=0x56275e0cdb40, pn=8, ps=1232 server | 1.063 DEBUG ECN probing: sent 10 probes server | 1.063 DEBUG ECN probing concluded with 10 probes sent server | 1.063 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1093, pto: None, probe: EnumSet(), paced: false } server | 1.063 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.064 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=9 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1093 server | TX -> Stream { stream_id: 4, offset: 3208, len: >>1051, fin: false } server | 1.064 DEBUG packet_sent this=0x56275e0cdb40, pn=9, ps=1093 server | 1.064 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 7.871639ms server | 1.064 DEBUG Setting timeout of 7.871639ms server | 1.064 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 7.848235ms server | 1.064 DEBUG Setting timeout of 7.848235ms server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.073 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=10 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 44 server | TX -> Ack { largest_acknowledged: 4, ack_delay: 2655, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.073 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.073 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 106.451612ms server | 1.073 DEBUG Setting timeout of 106.451612ms server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.073 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.073 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.073 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 106.423029ms server | 1.073 DEBUG Setting timeout of 106.423029ms server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=5 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 15, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=0] server | 1.083 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 server | 1.083 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11049/13591 ssthresh 18446744073709551615] slow start += 1271 server | 1.083 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11049/13591 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=11049, cwnd=13591, state=SlowStart, new_acked=1271 server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=11 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 4, offset: 4259, len: >>1190, fin: false } server | 1.083 DEBUG packet_sent this=0x56275e0cdb40, pn=11, ps=1232 server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=12 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 4, offset: 5449, len: >>1190, fin: false } server | 1.083 DEBUG packet_sent this=0x56275e0cdb40, pn=12, ps=1232 server | 1.083 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 105.328682ms server | 1.084 DEBUG Setting timeout of 105.328682ms server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 105.280542ms server | 1.084 DEBUG Setting timeout of 105.280542ms server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=6 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 4, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=1] server | 1.084 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 1.084 WARN ECN validation failed, no ECN counts in ACK frame server | 1.084 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12181/14923 ssthresh 18446744073709551615] slow start += 1332 server | 1.084 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12181/14923 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=12181, cwnd=14923, state=SlowStart, new_acked=1332 server | 1.084 DEBUG PMTUD probe of size 1380 succeeded server | 1.084 DEBUG PMTUD started with probe size 1420 server | 1.084 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=13 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 4, offset: 6639, len: >>1329, fin: false } server | 1.084 DEBUG packet_sent this=0x56275e0cdb40, pn=13, ps=1372 server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=14 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 7968, len: >>1290, fin: false } server | 1.084 DEBUG packet_sent this=0x56275e0cdb40, pn=14, ps=1332 server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 97.068507ms server | 1.084 DEBUG Setting timeout of 97.068507ms server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 97.04355ms server | 1.084 DEBUG Setting timeout of 97.04355ms server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=7 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 4, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=2] server | 1.085 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.085 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 13653/16155 ssthresh 18446744073709551615] slow start += 1232 server | 1.085 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 13653/16155 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=13653, cwnd=16155, state=SlowStart, new_acked=1232 server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.085 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 485.278µs server | 1.085 DEBUG Setting timeout of 485.278µs server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.085 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 432.519µs server | 1.085 DEBUG Setting timeout of 432.519µs server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=8 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: None } server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=3] server | 1.086 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 server | 1.086 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12421/17387 ssthresh 18446744073709551615] slow start += 1232 server | 1.086 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12421/17387 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=12421, cwnd=17387, state=SlowStart, new_acked=1232 server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.086 DEBUG CRYPTO for ap offset=0, len=302 server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=15 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1332 server | TX -> Stream { stream_id: 4, offset: 9258, len: 982, fin: true } server | TX -> Crypto { offset: 0, len: 302 } server | 1.086 DEBUG packet_sent this=0x56275e0cdb40, pn=15, ps=1332 server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.086 DEBUG CRYPTO for ap offset=302, len=19 server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=16 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 106 server | TX -> Crypto { offset: 302, len: 19 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 111, 101, 84, 212, 197, 176, 51, 255, 26, 107, 39, 216, 188, 209, 202, 40, 135, 171, 51, 91, 229, 220, 140, 57, 171, 75, 207, 130, 34, 90, 169, 150, 51, 103, 221, 30] } server | 1.086 DEBUG packet_sent this=0x56275e0cdb40, pn=16, ps=106 server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.086 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 85.660736ms server | 1.086 DEBUG Setting timeout of 85.660736ms server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.086 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 85.636801ms server | 1.086 DEBUG Setting timeout of 85.636801ms server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=9 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 5, first_ack_range: 4, ack_ranges: [], ecn_count: None } server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=4] server | 1.089 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.089 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12627/18619 ssthresh 18446744073709551615] slow start += 1232 server | 1.089 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12627/18619 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=12627, cwnd=18619, state=SlowStart, new_acked=1232 server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 79.489611ms server | 1.089 DEBUG Setting timeout of 79.489611ms server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 79.426313ms server | 1.089 DEBUG Setting timeout of 79.426313ms server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=10 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 5, ack_delay: 5, first_ack_range: 5, ack_ranges: [], ecn_count: None } server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=5] server | 1.090 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=5 server | 1.090 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11395/19851 ssthresh 18446744073709551615] slow start += 1232 server | 1.090 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11395/19851 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=11395, cwnd=19851, state=SlowStart, new_acked=1232 server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.090 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 74.353594ms server | 1.090 DEBUG Setting timeout of 74.353594ms server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.090 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.090 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 74.293131ms server | 1.090 DEBUG Setting timeout of 74.293131ms server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=11 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 5, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=6] server | 1.092 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.092 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10163/21083 ssthresh 18446744073709551615] slow start += 1232 server | 1.092 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10163/21083 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=10163, cwnd=21083, state=SlowStart, new_acked=1232 server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=17 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 40 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | 1.092 DEBUG packet_sent this=0x56275e0cdb40, pn=17, ps=41 server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.092 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 75.06793ms server | 1.092 DEBUG Setting timeout of 75.06793ms server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.092 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 75.035279ms server | 1.092 DEBUG Setting timeout of 75.035279ms server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=12 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 7, ack_delay: 4, first_ack_range: 7, ack_ranges: [], ecn_count: None } server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=7] server | 1.093 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=7 server | 1.093 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8972/22315 ssthresh 18446744073709551615] slow start += 1232 server | 1.093 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8972/22315 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=8972, cwnd=22315, state=SlowStart, new_acked=1232 server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 71.208655ms server | 1.093 DEBUG Setting timeout of 71.208655ms server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 71.14711ms server | 1.093 DEBUG Setting timeout of 71.14711ms server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=13 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 5, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=8] server | 1.095 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.095 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7740/23547 ssthresh 18446744073709551615] slow start += 1232 server | 1.095 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7740/23547 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=7740, cwnd=23547, state=SlowStart, new_acked=1232 server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.095 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 67.208278ms server | 1.095 DEBUG Setting timeout of 67.208278ms server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.095 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.095 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 67.102952ms server | 1.095 DEBUG Setting timeout of 67.102952ms server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=14 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 4, first_ack_range: 9, ack_ranges: [], ecn_count: None } server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=9] server | 1.096 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=9 server | 1.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6647/24640 ssthresh 18446744073709551615] slow start += 1093 server | 1.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6647/24640 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=6647, cwnd=24640, state=SlowStart, new_acked=1093 server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 64.10444ms server | 1.096 DEBUG Setting timeout of 64.10444ms server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 64.044227ms server | 1.096 DEBUG Setting timeout of 64.044227ms server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=15 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 11, ack_delay: 4, first_ack_range: 11, ack_ranges: [], ecn_count: None } server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=11] server | 1.115 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=11 server | 1.115 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5415/25872 ssthresh 18446744073709551615] slow start += 1232 server | 1.115 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5415/25872 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=5415, cwnd=25872, state=SlowStart, new_acked=1232 server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.115 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 44.133834ms server | 1.115 DEBUG Setting timeout of 44.133834ms server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.115 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 44.057642ms server | 1.115 DEBUG Setting timeout of 44.057642ms server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=16 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 12, ack_delay: 5, first_ack_range: 12, ack_ranges: [], ecn_count: None } server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=12] server | 1.116 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12 server | 1.116 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4183/27104 ssthresh 18446744073709551615] slow start += 1232 server | 1.116 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4183/27104 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=4183, cwnd=27104, state=SlowStart, new_acked=1232 server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.116 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.116 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 41.283905ms server | 1.116 DEBUG Setting timeout of 41.283905ms server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.116 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.116 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.116 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 41.226879ms server | 1.116 DEBUG Setting timeout of 41.226879ms server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=17 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 13, ack_delay: 4, first_ack_range: 13, ack_ranges: [], ecn_count: None } server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=13] server | 1.117 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=13 server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2811/28476 ssthresh 18446744073709551615] slow start += 1372 server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2811/28476 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=2811, cwnd=28476, state=SlowStart, new_acked=1372 server | 1.117 DEBUG PMTUD probe of size 1420 succeeded server | 1.117 DEBUG PMTUD started with probe size 1470 server | 1.117 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.117 DEBUG Sending PMTUD probe of size 1470, count 1 server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=18 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 1422 server | TX -> Ping server | TX -> Padding { len: 1383 } server | 1.117 DEBUG packet_sent this=0x56275e0cdb40, pn=18, ps=1422 server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 63.513494ms server | 1.117 DEBUG Setting timeout of 63.513494ms server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.117 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 63.484901ms server | 1.117 DEBUG Setting timeout of 63.484901ms server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=18 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 5, first_ack_range: 14, ack_ranges: [], ecn_count: None } server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] Rx ACK space=ap, ranges=[0..=14] server | 1.118 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14 server | 1.118 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2901/29808 ssthresh 18446744073709551615] slow start += 1332 server | 1.118 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2901/29808 ssthresh 18446744073709551615] on_packets_acked this=0x56275e0cdb40, limited=0, bytes_in_flight=2901, cwnd=29808, state=SlowStart, new_acked=1332 server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 62.039741ms server | 1.118 DEBUG Setting timeout of 62.039741ms server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] delay duration 61.974851ms server | 1.118 DEBUG Setting timeout of 61.974851ms server | 1.119 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=19 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 38 server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye" } server | 1.119 INFO [Server 811c23116aab6ccf54ab08473dfc55f3] ConnectionClose received. Error code: Application(0) frame type 0 reason kthxbye server | 1.119 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 815, tv_nsec: 546128747 } } server | 1.119 DEBUG [pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280] Path validated Instant { tv_sec: 815, tv_nsec: 356778626 } server | 1.119 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.119 DEBUG Building Short dcid Some(CID [20]: 23c26c77f44724a732c3bdeb0a00627e6c4847cd) server | 1.119 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 815, tv_nsec: 356778626 } server | 1.119 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] pn=19 type=Short pri-path:23c26c77f44724a732c3bdeb0a00627e6c4847cd [::]:443->[fd00:cafe:cafe::100]:35280 IpTos(Cs0, NotEct) len 47 server | TX -> Ack { largest_acknowledged: 19, ack_delay: 0, first_ack_range: 16, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.119 DEBUG Setting timeout of 189.26393ms server | 1.119 DEBUG Setting timeout of 189.252879ms server | 1.310 DEBUG [Server 811c23116aab6ccf54ab08473dfc55f3] State change from Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 815, tv_nsec: 546128747 } } -> Closed(Transport(PeerApplicationError(0))) server | 1.310 INFO Closing timer expired 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 10:36:33,907 Using the client's key log file. 2025-04-30 10:36:33,918 2025-04-30 10:36:33,918 Using the client's key log file. 2025-04-30 10:36:33,919 Using the client's key log file. 2025-04-30 10:36:33,927 2025-04-30 10:36:33,928 Using the client's key log file. 2025-04-30 10:36:34,490 Check of downloaded files succeeded. 2025-04-30 10:36:35,057 Check of downloaded files succeeded.