2025-04-30 08:44:06,638 Generated random file: zeylxtrpcr of size: 10240 2025-04-30 08:44:06,638 Requests: https://server4:443/zeylxtrpcr 2025-04-30 08:44:06,697 2025-04-30 08:44:06,698 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_5gl8j4wt/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_rcjxqfjf/ DOWNLOADS=/tmp/download_oxbge593/ SERVER_LOGS=/tmp/logs_server_p98it0o_ CLIENT_LOGS=/tmp/logs_client_mc9a8ank SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=privateoctopus/picoquic:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/zeylxtrpcr" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:44:18,797 Container sim Created Container server Recreate Container client 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 server | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + '[' -n retry ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.kVjKy7OCc2 server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password client | Setting up the simulation with setup.sh client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.kVjKy7OCc2 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Warning: output encryption option -nodes ignored with -export client | Setup.sh completed client | Waiting for the simulator to start server | + pk12util -d sql:/neqo/db -i /tmp/tmp.kVjKy7OCc2 -W '' client | wait-for-it.sh: 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 | 57:b4:ce:28:15:d1:ed:19:c2:af:b3:8a:2b:bd:35:49: server | 36:10:8a:77 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 08:44:06 2025 server | Not After : Sat May 10 08:44:06 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:ad:44:52:8b:a2:4f:8c:63:7a:a0:f8:64:78:e6:8d: server | 79:38:fa:c9:00:88:04:57:eb:05:c6:3c:c4:e1:3d:04: server | 3f:1b:f3:e7:87:a9:4d:dc:8a:60:eb:e5:96:e7:7e:f5: server | b2:bf:ac:15:3d:0c:21:53:71:be:42:0b:f3:fd:90:84: server | bc 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 | 4a:67:46:3d:bd:63:16:5d:77:c6:1e:65:f1:a4:d6:44: server | b1:f3:e9:83 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 66:b0:a3:ea:f3:82:fb:c7:1b:cd:4f:22:1b:0e:58:c0: server | 07:ea:bc:36 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:20:49:37:b5:b8:bd:2f:e4:ad:30:4e:25:22: server | e5:5e:95:e2:85:4f:c9:6a:5b:24:a9:4c:19:f7:30:2b: server | 32:22:92:39:02:21:00:eb:91:ba:d0:ab:1f:9f:31:4a: server | 6d:6a:79:cc:73:7d:38:82:ce:02:3d:30:3a:da:1a:49: server | 72:6b:7a:fd:37:82:24 server | Fingerprint (SHA-256): server | 79:FA:E6:C2:6D:F9:FE:21:2E:79:74:26:9E:22:F0:A2:02:CB:D8:9A:8A:51:35:DA:CD:16:7E:0C:24:14:A4:E1 server | Fingerprint (SHA1): server | 0C:E4:7D:8F:3D:86:8C:E9:6F:7E:3E:A0:BD:D5:9B:21:B8:91:38:22 server | server | Mozilla-CA-Policy: false (attribute missing) server | Certificate Trust Flags: server | SSL Flags: server | User server | Email Flags: server | User server | Object Signing Flags: server | User server | server | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT") server | + '[' retry = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test retry --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443' server | ++ tee -i -a /logs/server.log server | 0.000 DEBUG Logging initialized server | 0.002 DEBUG Default socket send buffer size is 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.797 DEBUG [Server] Unsupported version: 57414954 server | 0.797 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59596 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.032457594s server | 0.797 DEBUG [Server] Unsupported version: 57414954 server | 0.797 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59596 IpTos(Cs0, NotEct) len 15 server | 0.797 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.797 DEBUG [Server] Unsupported version: 57414954 server | 0.797 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59596 IpTos(Cs0, NotEct) len 15 server | 0.797 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: tcpdump: listening on eth1listening on eth0, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | , snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Starting picoquic client for test: retry client | Starting picoquic client ... client | Parsing server name from first request: https://server4:443/zeylxtrpcr client | Server set to: server4 client | Requests: https://server4:443/zeylxtrpcr client | parsing as client | rm: cannot remove '*.bin': No such file or directory client | Starting Picoquic (v1.1.26.1) connection to server = server4, port = 443 client | No token file present. Will create one as . client | Testing scenario: <-:/zeylxtrpcr;> client | Max stream id bidir remote before start = 0 (0) client | Starting client connection. Version = 1, I-CID: b9a10fa173f4b703 client | Max stream id bidir remote after start = -4 (0) client | Waiting for packets. server | 1.016 DEBUG [Server] Handle initial server | 1.016 INFO AddressValidation: no token; validating server | 1.016 INFO [Server] Send retry for CID [8]: b9a10fa173f4b703 server | 1.017 DEBUG [Server] type=Retry path:b9a10fa173f4b703 [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, NotEct) len 92 server | 1.049 DEBUG [Server] Handle initial server | 1.049 INFO AddressValidation: valid Retry token for b9a10fa173f4b703 server | 1.049 INFO [Server] Accept connection CID [8]: b9a10fa173f4b703 server | 1.049 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.050 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.050 INFO [Server ...] Received valid Initial packet with scid CID [8]: ce04f74f73806e7d dcid CID [10]: 97fd1d5eb3dde9d744b8 server | 1.050 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=97fd1d5eb3dde9d744b8 server | 1.050 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.050 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.050 DEBUG [Server 97fd1d5eb3dde9d744b8] State change from Init -> WaitInitial server | 1.050 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=83039 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 1252 server | -> RX Crypto { offset: 0, len: 285 } server | -> RX Padding { len: 864 } server | 1.050 DEBUG Read Ok(285) bytes server | 1.050 DEBUG 0-RTT: no token, no 0-RTT server | 1.051 DEBUG Read secret available for Handshake: SymKey [32]: 03dcf3479312999ac5413d1285eefeb03167e7e0ed2b26379e50fbdca8ff44b5 server | 1.051 DEBUG Write secret available for Handshake: SymKey [32]: 350e14924864ed4c2ccb0e7ddeaeb1a2f098f7bf56c90b1ded5edb514481441b server | 1.051 DEBUG Writing transport parameters, msg=8 server | 1.052 DEBUG Read secret available for ApplicationData: SymKey [32]: 86478eded57de53508fa7c1081fc5416199b6bc131dd6926d07af4d4d43a1c7d server | 1.052 DEBUG Write secret available for ApplicationData: SymKey [32]: 79a25b7630a8671394a9d043b7312a7b942a6006178aed4b8e349fd3d463f5f4 server | 1.052 DEBUG [Agent 0x55636913b710] state -> InProgress server | 1.052 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.052 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.052 DEBUG [Crypto] Handshake keys installed server | 1.052 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.052 DEBUG [Crypto] Application write key installed server | 1.052 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 323, tv_nsec: 172022346 } server | 1.052 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:41111] Make permanent server | 1.052 DEBUG [unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111] set as primary path server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] State change from WaitInitial -> Handshaking server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.052 DEBUG Building Initial dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG CRYPTO for in offset=0, len=123 server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=0 type=Initial pri-unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 183 server | TX -> Ack { largest_acknowledged: 83039, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } server | TX -> Crypto { offset: 0, len: 123 } server | 1.052 DEBUG Building Handshake dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG CRYPTO for hs offset=0, len=733 server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=0 type=Handshake pri-unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 964 server | TX -> Crypto { offset: 0, len: 733 } server | 1.052 DEBUG packet_sent this=0x556369182b40, pn=0, ps=781 server | 1.052 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] pad Initial from 964 to PLPMTU 1232 server | 1.052 DEBUG packet_sent this=0x556369182b40, pn=0, ps=451 server | 1.052 DEBUG ECN probing: sent 1 probes server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.052 DEBUG Building Initial dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG Building Handshake dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.052 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 296.573489ms server | 1.052 DEBUG Setting timeout of 296.573489ms server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.052 DEBUG Building Initial dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG Building Handshake dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.052 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.052 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.052 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 296.542892ms server | 1.052 DEBUG Setting timeout of 296.542892ms client | Client port (AF=2): 38816. client | Negotiated ALPN: hq-interop client | Almost ready! client | client | Connection established. Version = 1, I-CID: 97fd1d5eb3dde9d7, verified: 1 client | Opening stream 0 to GET /zeylxtrpcr server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] Drop packet number space in server | 1.084 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.084 INFO [pri-unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111] discarding a packet without an RTT estimate; guessing RTT=35.551658ms server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=0 type=Handshake pri-unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 94 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 32, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Crypto { offset: 0, len: 36 } server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=hs, ranges=[0..=0] server | 1.084 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.084 DEBUG on_packets_acked this=0x556369182b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=781 server | 1.084 DEBUG Acked crypto frame space=hs offset=0 length=733 server | 1.084 DEBUG Read Ok(36) bytes server | 1.084 DEBUG [Agent 0x55636913b710] 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.084 DEBUG [Server 97fd1d5eb3dde9d744b8] TLS connection complete server | 1.084 DEBUG [pri-unv-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111] Path validated Instant { tv_sec: 323, tv_nsec: 207574004 } server | 1.084 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.084 DEBUG [Crypto] application read keys installed server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] State change from Handshaking -> Connected server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] State change from Connected -> Confirmed server | 1.084 DEBUG PMTUD started with probe size 1380 server | 1.084 INFO [Server 97fd1d5eb3dde9d744b8] Connection established server | 1.084 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 323, tv_nsec: 207574004 } server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=0 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 311 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [196, 68, 0, 199, 209, 119, 138, 74], stateless_reset_token: [140, 103, 22, 225, 233, 75, 75, 46, 61, 208, 243, 214, 99, 234, 47, 126] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [24, 12, 101, 170, 92, 196, 3, 37], stateless_reset_token: [150, 220, 157, 84, 124, 128, 109, 26, 56, 238, 181, 78, 251, 81, 243, 214] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [236, 72, 15, 42, 29, 253, 244, 188], stateless_reset_token: [107, 177, 66, 15, 78, 186, 246, 60, 199, 125, 55, 184, 235, 192, 34, 147] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [223, 77, 86, 198, 7, 50, 250, 185], stateless_reset_token: [168, 55, 132, 15, 244, 38, 12, 177, 66, 40, 39, 102, 158, 253, 156, 187] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [247, 8, 35, 244, 8, 190, 17, 217], stateless_reset_token: [191, 29, 226, 236, 7, 9, 26, 76, 62, 121, 109, 32, 77, 120, 172, 15] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [194, 80, 217, 156, 239, 88, 28, 18], stateless_reset_token: [185, 137, 244, 150, 188, 54, 238, 81, 147, 40, 157, 214, 19, 14, 181, 86] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [37, 189, 128, 239, 9, 179, 245, 5], stateless_reset_token: [104, 245, 215, 180, 100, 203, 99, 52, 22, 125, 247, 133, 50, 52, 161, 132] } server | -> RX Padding { len: 87 } server | 1.084 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 323, tv_nsec: 227574004 } server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.084 DEBUG Building Handshake dcid Some(CID [8]: ce04f74f73806e7d) scid Some(CID [10]: d874d3c3edcead9705bd) server | 1.084 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=1 type=Handshake pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 52 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] Drop packet number space hs server | 1.085 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.085 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=0 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [90, 251, 177, 202, 32, 226, 15, 206, 143, 27], stateless_reset_token: [0, 198, 60, 203, 252, 94, 27, 12, 192, 82, 191, 15, 161, 219, 44, 30] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [167, 127, 240, 108, 30, 236, 105, 132, 217, 51], stateless_reset_token: [167, 60, 212, 22, 121, 254, 139, 20, 251, 13, 137, 152, 87, 11, 116, 76] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [117, 54, 86, 39, 215, 39, 32, 145, 45, 232], stateless_reset_token: [202, 3, 6, 188, 248, 4, 214, 113, 69, 151, 245, 119, 25, 42, 177, 230] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [22, 205, 0, 220, 72, 0, 136, 255, 217, 94], stateless_reset_token: [6, 21, 148, 122, 152, 237, 77, 224, 65, 145, 94, 246, 173, 204, 123, 196] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [5, 143, 112, 210, 128, 231, 226, 37, 31, 120], stateless_reset_token: [5, 51, 152, 185, 164, 241, 168, 3, 182, 216, 59, 71, 52, 37, 78, 56] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [68, 128, 239, 145, 242, 73, 3, 20, 166, 34], stateless_reset_token: [188, 141, 67, 138, 129, 197, 170, 182, 62, 117, 92, 201, 207, 107, 141, 116] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [102, 155, 188, 113, 199, 35, 80, 239, 111, 2], stateless_reset_token: [22, 61, 197, 14, 50, 100, 140, 236, 231, 202, 125, 17, 153, 197, 50, 239] } server | TX -> Padding { len: 1043 } server | 1.085 DEBUG packet_sent this=0x556369182b40, pn=0, ps=1280 server | 1.085 DEBUG ECN probing: sent 2 probes server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.085 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.085 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=1 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.085 DEBUG packet_sent this=0x556369182b40, pn=1, ps=1332 server | 1.085 DEBUG ECN probing: sent 3 probes server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.085 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.36666ms server | 1.085 DEBUG Setting timeout of 1.36666ms server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=1 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Padding { len: 7 } server | 1.085 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 323, tv_nsec: 208224338 } server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=2 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 34 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } server | 1.085 DEBUG ECN probing: sent 4 probes server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.085 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.085 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.318925ms server | 1.085 DEBUG Setting timeout of 1.318925ms server | 1.086 DEBUG [Server 97fd1d5eb3dde9d744b8] send session ticket 406f0008b9a10fa173f4b7030104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0ad874d3c3edcead9705bd100a97fd1d5eb3dde9d744b8110c000000012aaa8a4a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.086 DEBUG Path = 'zeylxtrpcr' server | 1.086 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.086 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.086 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.086 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 323.435µs server | 1.086 DEBUG Setting timeout of 323.435µs server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.087 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=3 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 1.087 DEBUG packet_sent this=0x556369182b40, pn=3, ps=1232 server | 1.087 DEBUG ECN probing: sent 5 probes server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.087 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 949.668µs server | 1.087 DEBUG Setting timeout of 949.668µs server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.087 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.087 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 930.762µs server | 1.087 DEBUG Setting timeout of 930.762µs server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=4 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 1.089 DEBUG packet_sent this=0x556369182b40, pn=4, ps=1232 server | 1.089 DEBUG ECN probing: sent 6 probes server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=5 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 1.089 DEBUG packet_sent this=0x556369182b40, pn=5, ps=1232 server | 1.089 DEBUG ECN probing: sent 7 probes server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.089 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.7178ms server | 1.089 DEBUG Setting timeout of 1.7178ms server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.089 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.089 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.697181ms server | 1.089 DEBUG Setting timeout of 1.697181ms server | 1.092 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.092 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.092 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=6 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false } server | 1.092 DEBUG packet_sent this=0x556369182b40, pn=6, ps=1232 server | 1.092 DEBUG ECN probing: sent 8 probes server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.093 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=7 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4810, len: >>1202, fin: false } server | 1.093 DEBUG packet_sent this=0x556369182b40, pn=7, ps=1232 server | 1.093 DEBUG ECN probing: sent 9 probes server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.093 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.651547ms server | 1.093 DEBUG Setting timeout of 1.651547ms server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.093 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.093 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.093 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.624957ms server | 1.093 DEBUG Setting timeout of 1.624957ms server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.095 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=8 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 6012, len: >>1202, fin: false } server | 1.095 DEBUG packet_sent this=0x556369182b40, pn=8, ps=1232 server | 1.095 DEBUG ECN probing: sent 10 probes server | 1.095 DEBUG ECN probing concluded with 10 probes sent server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.237153ms server | 1.095 DEBUG Setting timeout of 1.237153ms server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 1.211536ms server | 1.095 DEBUG Setting timeout of 1.211536ms server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=9 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 7214, len: >>1202, fin: false } server | 1.097 DEBUG packet_sent this=0x556369182b40, pn=9, ps=1232 server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1084, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=10 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, NotEct) len 1084 server | TX -> Stream { stream_id: 0, offset: 8416, len: >>1054, fin: false } server | 1.097 DEBUG packet_sent this=0x556369182b40, pn=10, ps=1084 server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 98.80292ms server | 1.097 DEBUG Setting timeout of 98.80292ms server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.097 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 98.78174ms server | 1.097 DEBUG Setting timeout of 98.78174ms server | 1.117 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=2 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 2, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.117 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=2] server | 1.117 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.117 INFO ECN validation succeeded, path is capable server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9708/14932 ssthresh 18446744073709551615] slow start += 2612 server | 1.117 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9708/14932 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=9708, cwnd=14932, state=SlowStart, new_acked=2612 server | 1.117 DEBUG PMTUD probe of size 1380 succeeded server | 1.117 DEBUG PMTUD started with probe size 1420 server | 1.117 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.117 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.118 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.118 DEBUG CRYPTO for ap offset=0, len=321 server | 1.118 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=11 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 9470, len: 770, fin: true } server | TX -> Crypto { offset: 0, len: 321 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 122, 145, 214, 210, 54, 215, 172, 227, 245, 252, 2, 127, 123, 11, 107, 33, 201, 234, 110, 8, 103, 52, 50, 49, 15, 171, 162, 163, 246, 97, 59, 35, 73, 148, 3, 155] } server | TX -> Padding { len: 199 } server | 1.118 DEBUG packet_sent this=0x556369182b40, pn=11, ps=1372 server | 1.118 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 87.89653ms server | 1.118 DEBUG Setting timeout of 87.89653ms server | 1.118 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 87.872656ms server | 1.118 DEBUG Setting timeout of 87.872656ms server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=3 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 5, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=4] server | 1.121 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.121 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8616/17396 ssthresh 18446744073709551615] slow start += 2464 server | 1.121 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8616/17396 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=8616, cwnd=17396, state=SlowStart, new_acked=2464 server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.121 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.121 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 77.450527ms server | 1.121 DEBUG Setting timeout of 77.450527ms server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.121 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.121 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.121 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 77.389022ms server | 1.121 DEBUG Setting timeout of 77.389022ms server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=4 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 5, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=6] server | 1.124 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.124 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6152/19860 ssthresh 18446744073709551615] slow start += 2464 server | 1.124 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6152/19860 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=6152, cwnd=19860, state=SlowStart, new_acked=2464 server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.124 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.124 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 67.973042ms server | 1.124 DEBUG Setting timeout of 67.973042ms server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.124 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.124 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.124 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 67.92377ms server | 1.124 DEBUG Setting timeout of 67.92377ms server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=5 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=8] server | 1.126 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.126 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3688/22324 ssthresh 18446744073709551615] slow start += 2464 server | 1.126 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3688/22324 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=3688, cwnd=22324, state=SlowStart, new_acked=2464 server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.126 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.126 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 60.690825ms server | 1.126 DEBUG Setting timeout of 60.690825ms server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.126 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.126 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.126 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 60.64037ms server | 1.126 DEBUG Setting timeout of 60.64037ms server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=6 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 10, ack_delay: 3, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=10] server | 1.129 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10 server | 1.129 WARN ECN validation failed, no ECT(0) packets were newly acked server | 1.129 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] slow start += 2316 server | 1.129 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=1372, cwnd=24640, state=SlowStart, new_acked=2316 server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.129 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.129 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 52.735762ms server | 1.129 DEBUG Setting timeout of 52.735762ms server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.129 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.129 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.129 DEBUG [Server 97fd1d5eb3dde9d744b8] delay duration 52.684487ms server | 1.129 DEBUG Setting timeout of 52.684487ms client | Stream 0 ended after 10240 bytes client | All done, Closing the connection. server | 1.149 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=7 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, Ect1) len 39 server | -> RX Ack { largest_acknowledged: 11, ack_delay: 9, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" } server | 1.149 DEBUG [Server 97fd1d5eb3dde9d744b8] Rx ACK space=ap, ranges=[0..=11] server | 1.149 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=11 server | 1.149 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] slow start += 1372 server | 1.149 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] on_packets_acked this=0x556369182b40, limited=0, bytes_in_flight=0, cwnd=26012, state=SlowStart, new_acked=1372 server | 1.149 DEBUG PMTUD probe of size 1420 succeeded server | 1.149 DEBUG PMTUD started with probe size 1470 server | 1.149 DEBUG PLPMTU changed from 1332 to 1372, updating pacer server | 1.149 DEBUG Acked crypto frame space=ap offset=0 length=321 server | 1.149 INFO [Server 97fd1d5eb3dde9d744b8] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 1.149 DEBUG [Server 97fd1d5eb3dde9d744b8] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 323, tv_nsec: 456170279 } } server | 1.149 DEBUG [pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111] Path validated Instant { tv_sec: 323, tv_nsec: 272720480 } server | 1.149 DEBUG [Server 97fd1d5eb3dde9d744b8] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false } server | 1.149 DEBUG Building Short dcid Some(CID [8]: ce04f74f73806e7d) server | 1.149 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 323, tv_nsec: 272720480 } server | 1.149 DEBUG [Server 97fd1d5eb3dde9d744b8] pn=12 type=Short pri-path:ce04f74f73806e7d [::]:443->[::ffff:193.167.0.100]:41111 IpTos(Cs0, NotEct) len 38 server | TX -> Ack { largest_acknowledged: 7, ack_delay: 0, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 8, Ect0: 0, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.149 DEBUG Setting timeout of 183.294098ms server | 1.149 DEBUG Setting timeout of 183.281795ms client | Received a request to close the connection. client | The connection is closed! client | Address Discovery mode: 0 / 0 (0:0) client | Quic Bit was greased by the client. client | Quic Bit was greased by the server. client | ECN was received (ect0: 10, ect1: 0, ce: 0). client | ECN was acknowledged (ect0: 0, ect1: 2, ce: 0). client | Received 10240 bytes in 0.171820 seconds, 0.476778 Mbps. client | Sent 17 bytes in 0.171820 seconds, 0.000792 Mbps. client | max_data_local: 1048576 client | max_stream_data_local: 2097152 client | max_data_remote: 4611686018427387903 client | max_stream_data_remote: 1048576 client | ack_delay_remote: 1000 ... 4083 client | max_ack_gap_remote: 2 client | ack_delay_local: 25000 ... 25000 client | max_ack_gap_local: 2 client | max_mtu_sent: 1252 client | max_mtu_received: 1372 client | System call duration max: 4 client | System call duration smoothed: 0 client | System call duration deviation: 0 client | Received ticket from server4 (hq-interop): client | ticket time = 1746002648443, kx = 17, suite = 1301, 317 ticket, 32 secret. client | lifetime = 172800, age_add = d9ea0105, 2 nonce, 290 ticket, 12 extensions. client | ticket extensions: 14906 (0 bytes),42(ED: ffffffff), client | Client exit with code = 0 client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:44:18,889 Using the client's key log file. 2025-04-30 08:44:18,898 2025-04-30 08:44:18,898 Using the client's key log file. 2025-04-30 08:44:18,898 Using the client's key log file. 2025-04-30 08:44:18,906 2025-04-30 08:44:18,906 Using the client's key log file. 2025-04-30 08:44:19,184 At least one QUIC packet could not be decrypted 2025-04-30 08:44:19,184 Packet (Length: 1374) Layer ETH : Destination: 02:42:c1:a7:64:02 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Source: 02:42:c1:a7:64:64 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Type: IPv4 (0x0800) Stream index: 4 Layer IP : 0100 .... = Version: 4 .... 0101 = Header Length: 20 bytes (5) Differentiated Services Field: 0x02 (DSCP: CS0, ECN: ECT(0)) 0000 00.. = Differentiated Services Codepoint: Default (0) .... ..10 = Explicit Congestion Notification: ECN-Capable Transport codepoint '10' (2) Total Length: 1360 Identification: 0x0000 (0) 010. .... = Flags: 0x2, Don't fragment 0... .... = Reserved bit: Not set .1.. .... = Don't fragment: Set ..0. .... = More fragments: Not set ...0 0000 0000 0000 = Fragment Offset: 0 Time to Live: 64 Protocol: UDP (17) Header Checksum: 0x4d84 [validation disabled] Header checksum status: Unverified Source Address: 193.167.100.100 Destination Address: 193.167.0.100 Stream index: 0 Layer UDP : Source Port: 443 Destination Port: 41111 Length: 1340 Checksum: 0xbeea [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 68.260000 milliseconds Time since previous frame: 556.000 microseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 52 1... .... = Header Form: Long Header (1) .1.. .... = Fixed Bit: True ..10 .... = Packet Type: Handshake (2) Version: 1 (0x00000001) Destination Connection ID Length: 8 Destination Connection ID: ce04f74f73806e7d Source Connection ID Length: 10 Source Connection ID: d874d3c3edcead9705bd Length: 25 Expert Info (Warning/Decryption): Failed to create decryption context: Secrets are not available Failed to create decryption context: Secrets are not available Severity level: Warning Group: Decryption Remaining Payload: 99cb759dd55f9d10cfac7671e4aabd43748fad3028f4b0726b Layer QUIC : Packet Length: 1280 QUIC Short Header DCID=ce04f74f73806e7d 0... .... = Header Form: Short Header (0) .0.. .... = Fixed Bit: False ..0. .... = Spin Bit: False Destination Connection ID: ce04f74f73806e7d Remaining Payload […]: 96a689ff3cc71cf9a9ea94f908cbc465d5fd07fb05b064fdd488bfafb48c14e0b6c9d20cb8ef5fd7b9921deeae79b3a8ef3063a02a135ddcac5602a69dd53b44872cf41b870bef7ae4668fd156cb3dc648f5612f0690b7dc05e4f69579ac43a90afd6e2aaffa8568e30f6e 2025-04-30 08:44:19,458 At least one QUIC packet could not be decrypted 2025-04-30 08:44:19,458 Packet (Length: 1374) Layer ETH : Destination: 02:42:c1:a7:64:02 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Source: 02:42:c1:a7:64:64 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Type: IPv4 (0x0800) Stream index: 4 Layer IP : 0100 .... = Version: 4 .... 0101 = Header Length: 20 bytes (5) Differentiated Services Field: 0x02 (DSCP: CS0, ECN: ECT(0)) 0000 00.. = Differentiated Services Codepoint: Default (0) .... ..10 = Explicit Congestion Notification: ECN-Capable Transport codepoint '10' (2) Total Length: 1360 Identification: 0x0000 (0) 010. .... = Flags: 0x2, Don't fragment 0... .... = Reserved bit: Not set .1.. .... = Don't fragment: Set ..0. .... = More fragments: Not set ...0 0000 0000 0000 = Fragment Offset: 0 Time to Live: 64 Protocol: UDP (17) Header Checksum: 0x4d84 [validation disabled] Header checksum status: Unverified Source Address: 193.167.100.100 Destination Address: 193.167.0.100 Stream index: 0 Layer UDP : Source Port: 443 Destination Port: 41111 Length: 1340 Checksum: 0xbeea [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 68.260000 milliseconds Time since previous frame: 556.000 microseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 52 1... .... = Header Form: Long Header (1) .1.. .... = Fixed Bit: True ..10 .... = Packet Type: Handshake (2) Version: 1 (0x00000001) Destination Connection ID Length: 8 Destination Connection ID: ce04f74f73806e7d Source Connection ID Length: 10 Source Connection ID: d874d3c3edcead9705bd Length: 25 Expert Info (Warning/Decryption): Failed to create decryption context: Secrets are not available Failed to create decryption context: Secrets are not available Severity level: Warning Group: Decryption Remaining Payload: 99cb759dd55f9d10cfac7671e4aabd43748fad3028f4b0726b Layer QUIC : Packet Length: 1280 QUIC Short Header DCID=ce04f74f73806e7d 0... .... = Header Form: Short Header (0) .0.. .... = Fixed Bit: False ..0. .... = Spin Bit: False Destination Connection ID: ce04f74f73806e7d Remaining Payload […]: 96a689ff3cc71cf9a9ea94f908cbc465d5fd07fb05b064fdd488bfafb48c14e0b6c9d20cb8ef5fd7b9921deeae79b3a8ef3063a02a135ddcac5602a69dd53b44872cf41b870bef7ae4668fd156cb3dc648f5612f0690b7dc05e4f69579ac43a90afd6e2aaffa8568e30f6e 2025-04-30 08:44:19,459 Check of downloaded files succeeded. 2025-04-30 08:44:19,733 At least one QUIC packet could not be decrypted 2025-04-30 08:44:19,734 Packet (Length: 1374) Layer ETH : Destination: 02:42:c1:a7:00:64 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Source: 02:42:c1:a7:00:02 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Type: IPv4 (0x0800) Stream index: 2 Layer IP : 0100 .... = Version: 4 .... 0101 = Header Length: 20 bytes (5) Differentiated Services Field: 0x02 (DSCP: CS0, ECN: ECT(0)) 0000 00.. = Differentiated Services Codepoint: Default (0) .... ..10 = Explicit Congestion Notification: ECN-Capable Transport codepoint '10' (2) Total Length: 1360 Identification: 0x0000 (0) 010. .... = Flags: 0x2, Don't fragment 0... .... = Reserved bit: Not set .1.. .... = Don't fragment: Set ..0. .... = More fragments: Not set ...0 0000 0000 0000 = Fragment Offset: 0 Time to Live: 62 Protocol: UDP (17) Header Checksum: 0x4f84 [validation disabled] Header checksum status: Unverified Source Address: 193.167.100.100 Destination Address: 193.167.0.100 Stream index: 1 Layer UDP : Source Port: 443 Destination Port: 41111 Length: 1340 Checksum: 0xbeea [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 105.934000 milliseconds Time since previous frame: 32.328000 milliseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 52 1... .... = Header Form: Long Header (1) .1.. .... = Fixed Bit: True ..10 .... = Packet Type: Handshake (2) Version: 1 (0x00000001) Destination Connection ID Length: 8 Destination Connection ID: ce04f74f73806e7d Source Connection ID Length: 10 Source Connection ID: d874d3c3edcead9705bd Length: 25 Expert Info (Warning/Decryption): Failed to create decryption context: Secrets are not available Failed to create decryption context: Secrets are not available Severity level: Warning Group: Decryption Remaining Payload: 99cb759dd55f9d10cfac7671e4aabd43748fad3028f4b0726b Layer QUIC : Packet Length: 1280 QUIC Short Header DCID=ce04f74f73806e7d 0... .... = Header Form: Short Header (0) .0.. .... = Fixed Bit: False ..0. .... = Spin Bit: False Destination Connection ID: ce04f74f73806e7d Remaining Payload […]: 96a689ff3cc71cf9a9ea94f908cbc465d5fd07fb05b064fdd488bfafb48c14e0b6c9d20cb8ef5fd7b9921deeae79b3a8ef3063a02a135ddcac5602a69dd53b44872cf41b870bef7ae4668fd156cb3dc648f5612f0690b7dc05e4f69579ac43a90afd6e2aaffa8568e30f6e 2025-04-30 08:44:20,010 At least one QUIC packet could not be decrypted 2025-04-30 08:44:20,011 Packet (Length: 447) Layer ETH : Destination: 02:42:c1:a7:00:02 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Source: 02:42:c1:a7:00:64 .... ..1. .... .... .... .... = LG bit: Locally administered address (this is NOT the factory default) .... ...0 .... .... .... .... = IG bit: Individual address (unicast) Type: IPv4 (0x0800) Stream index: 2 Layer IP : 0100 .... = Version: 4 .... 0101 = Header Length: 20 bytes (5) Differentiated Services Field: 0x01 (DSCP: CS0, ECN: ECT(1)) 0000 00.. = Differentiated Services Codepoint: Default (0) .... ..01 = Explicit Congestion Notification: ECN-Capable Transport codepoint '01' (1) Total Length: 433 Identification: 0x0000 (0) 010. .... = Flags: 0x2, Don't fragment 0... .... = Reserved bit: Not set .1.. .... = Don't fragment: Set ..0. .... = More fragments: Not set ...0 0000 0000 0000 = Fragment Offset: 0 Time to Live: 64 Protocol: UDP (17) Header Checksum: 0x5124 [validation disabled] Header checksum status: Unverified Source Address: 193.167.0.100 Destination Address: 193.167.100.100 Stream index: 1 Layer UDP : Source Port: 41111 Destination Port: 443 Length: 413 Checksum: 0xce7e [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 5 Timestamps Time since first frame: 73.476000 milliseconds Time since previous frame: 470.000 microseconds UDP payload (405 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 94 1... .... = Header Form: Long Header (1) .0.. .... = Fixed Bit: False ..10 .... = Packet Type: Handshake (2) Version: 1 (0x00000001) Destination Connection ID Length: 10 Destination Connection ID: d874d3c3edcead9705bd Source Connection ID Length: 8 Source Connection ID: ce04f74f73806e7d Length: 67 Expert Info (Warning/Decryption): Failed to create decryption context: Secrets are not available Failed to create decryption context: Secrets are not available Severity level: Warning Group: Decryption Remaining Payload: e133b87265f4be9e775efb2c361e103ba0dbf326996b9d931ecc5d373dae78474a59aaed923dd0f72e847161f801e701343527a5c6ad365aea0d266b468253aa88704d Layer QUIC : Packet Length: 311 QUIC Short Header DCID=d874d3c3edcead9705bd 0... .... = Header Form: Short Header (0) .1.. .... = Fixed Bit: True ..0. .... = Spin Bit: False Destination Connection ID: d874d3c3edcead9705bd Expert Info (Warning/Decryption): Failed to create decryption context: Secrets are not available Failed to create decryption context: Secrets are not available Severity level: Warning Group: Decryption Remaining Payload […]: dade5172582c23bfd773b3901216041a663b873873536b30eb293ff647cc5a5a7cdd7c79e538a0f1de330c0f5938915fd457394b986ae1713e5303e6a2873a863db1b92c0f8a6fbd2c11619d44d315dab98c98c58e583b9f179580b22cb31d6c3f2ddabd28cc51a6c8dfdc 2025-04-30 08:44:20,012 Check of Retry succeeded. Token used: 526574727901008b8c405176989560978e813d25cb7bcc07a683dfd84f5f6959a2e429a7a0f0116b115965c52b6fa8a7eec73b