2025-04-30 12:25:07,854 Generated random file: jmcowrgtsp of size: 10240 2025-04-30 12:25:07,854 Requests: https://server4:443/jmcowrgtsp 2025-04-30 12:25:07,912 2025-04-30 12:25:07,912 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_ww55055v/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_efte28mq/ DOWNLOADS=/tmp/download_zkler1tx/ SERVER_LOGS=/tmp/logs_server_qy3oijjk CLIENT_LOGS=/tmp/logs_client_grjgxlzk SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=aiortc/aioquic-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/jmcowrgtsp" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 12:25:20,475 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 client | Setting up routes... client | Actual changes: client | tx-checksumming: off client | tx-checksum-ip-generic: off client | tx-checksum-sctp: off client | tcp-segmentation-offload: off client | tx-tcp-segmentation: off [requested on] client | tx-tcp-ecn-segmentation: off [requested on] client | tx-tcp-mangleid-segmentation: off [requested on] client | tx-tcp6-segmentation: off [requested on] client | tx-udp-segmentation: off [requested on] 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 client | Endpoint's IPv4 address is 193.167.0.100 server | + P12CERT=/tmp/tmp.PdCXZQLvLG server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.PdCXZQLvLG server | Warning: output encryption option -nodes ignored with -export client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | + pk12util -d sql:/neqo/db -i /tmp/tmp.PdCXZQLvLG -W '' server | pk12util: PKCS12 IMPORT SUCCESSFUL server | + certutil -L -d sql:/neqo/db -n cert server | Certificate: server | Data: server | Version: 3 (0x2) server | Serial Number: server | 5b:7f:8d:7f:87:6a:36:c9:ac:e8:6b:46:3b:51:06:1e: server | ad:77:cc:47 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Wed Apr 30 12:25:07 2025 server | Not After : Sat May 10 12:25:07 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:c9:16:1b:53:4e:65:30:ae:2a:84:e9:72:b0:7f:a4: server | 91:5b:4f:1d:10:a4:71:01:96:77:c5:b0:cb:e8:93:c4: server | 1d:ff:45:31:26:09:97:cb:ad:96:b5:3e:8f:d4:3f:85: server | 82:99:94:49:d3:08:88:c7:40:ff:72:38:21:ff:13:ee: server | 10 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 | d1:e7:0d:cd:b2:0e:bd:5a:1b:20:0b:be:30:78:4d:5d: server | a9:bf:64:4b server | server | Name: Certificate Authority Key Identifier server | Key ID: server | b4:ee:4d:3d:82:15:da:75:54:40:56:a6:f6:77:db:66: server | 61:26:9f:50 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:21:00:a6:16:e0:95:13:b0:a2:f4:aa:4c:4c: server | 2c:3c:57:19:a2:41:94:5e:22:58:0e:2a:2d:9d:33:bd: server | 4e:f5:69:48:1e:02:20:10:97:4b:54:a4:6a:21:15:8b: server | 48:ed:72:4f:d9:cc:a5:f5:37:17:a8:80:a0:83:b1:39: server | 33:96:b7:35:ff:3e:f1 server | Fingerprint (SHA-256): server | C5:9B:89:44:15:84:BA:EC:67:41:48:4F:78:D0:63:B2:07:5C:1F:92:82:E6:48:11:D8:13:78:EB:8E:16:AD:4F server | Fingerprint (SHA1): server | 35:19:B0:D4:FE:02:56:C8:30:2C:F6:F0:02:20:B9:16:1F:6C:E8:84 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]:54568 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.047872457s server | 0.797 DEBUG [Server] Unsupported version: 57414954 server | 0.797 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:54568 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]:54568 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: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Starting client server | 1.185 DEBUG [Server] Handle initial server | 1.185 INFO AddressValidation: no token; validating server | 1.185 INFO [Server] Send retry for CID [8]: e159c43a115490b8 server | 1.185 DEBUG [Server] type=Retry path:e159c43a115490b8 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 92 server | 1.219 DEBUG [Server] Handle initial server | 1.219 INFO AddressValidation: valid Retry token for e159c43a115490b8 server | 1.219 INFO [Server] Accept connection CID [8]: e159c43a115490b8 server | 1.219 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.220 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.220 INFO [Server ...] Received valid Initial packet with scid CID [8]: cd0362c53e6db8a3 dcid CID [10]: 4cf52679a3050e167f39 server | 1.220 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=4cf52679a3050e167f39 server | 1.220 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.221 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.221 DEBUG [Server 4cf52679a3050e167f39] State change from Init -> WaitInitial server | 1.221 DEBUG [Server 4cf52679a3050e167f39] pn=1 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 583 server | -> RX Crypto { offset: 0, len: 482 } server | 1.221 DEBUG Read Ok(482) bytes server | 1.221 DEBUG 0-RTT: no token, no 0-RTT server | 1.221 DEBUG Read secret available for Handshake: SymKey [32]: 76158d96f85964d8fa27b23bbc5110017306d4524feb010b2d8228c306b79954 server | 1.221 DEBUG Write secret available for Handshake: SymKey [32]: 5f9e1c80e316cf97da4f559d738b2096ec60990bac3c845f17dc3d871e41d6f6 server | 1.221 DEBUG Writing transport parameters, msg=8 server | 1.221 DEBUG Read secret available for ApplicationData: SymKey [32]: dab9b7450dbc8675eae6c3983af6c850513ad1e3fa858299ba0b47bc49475bac server | 1.221 DEBUG Write secret available for ApplicationData: SymKey [32]: 8e06d17b5ed59e2a5aff8b912ce46b84ae1cd1fcb5e14f1cfb2f10e8de372b64 server | 1.221 DEBUG [Agent 0x565299f7e710] state -> InProgress server | 1.221 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.221 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.222 DEBUG [Crypto] Handshake keys installed server | 1.222 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.222 DEBUG [Crypto] Application write key installed server | 1.222 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 551, tv_nsec: 778027832 } server | 1.222 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:44290] Make permanent server | 1.222 DEBUG [unv-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290] set as primary path server | 1.222 DEBUG [Server 4cf52679a3050e167f39] State change from WaitInitial -> Handshaking server | 1.222 WARN [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 1.222 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.222 DEBUG Building Initial dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG CRYPTO for in offset=0, len=90 server | 1.222 DEBUG [Server 4cf52679a3050e167f39] pn=0 type=Initial pri-unv-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 144 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 1.222 DEBUG Building Handshake dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG CRYPTO for hs offset=0, len=736 server | 1.222 DEBUG [Server 4cf52679a3050e167f39] pn=0 type=Handshake pri-unv-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 928 server | TX -> Crypto { offset: 0, len: 736 } server | 1.222 DEBUG packet_sent this=0x565299fc5b40, pn=0, ps=784 server | 1.222 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.222 DEBUG [Server 4cf52679a3050e167f39] pad Initial from 928 to PLPMTU 1232 server | 1.222 DEBUG packet_sent this=0x565299fc5b40, pn=0, ps=448 server | 1.222 DEBUG ECN probing: sent 1 probes server | 1.222 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.222 DEBUG Building Initial dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG Building Handshake dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.222 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.222 DEBUG [Server 4cf52679a3050e167f39] delay duration 297.070055ms server | 1.222 DEBUG Setting timeout of 297.070055ms server | 1.222 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.222 DEBUG Building Initial dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG Building Handshake dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.222 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.222 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.222 DEBUG [Server 4cf52679a3050e167f39] delay duration 297.035892ms server | 1.222 DEBUG Setting timeout of 297.035892ms server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=2 type=Initial pri-unv-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 103 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 252, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=in, ranges=[0..=0] server | 1.257 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.257 DEBUG on_packets_acked this=0x565299fc5b40, limited=1, bytes_in_flight=784, cwnd=12320, state=SlowStart, new_acked=448 server | 1.257 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.257 DEBUG [pri-unv-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290] Path validated Instant { tv_sec: 551, tv_nsec: 815805031 } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] Drop packet number space in server | 1.257 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=3 type=Handshake pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 91 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 252, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=hs, ranges=[0..=0] server | 1.257 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.257 DEBUG on_packets_acked this=0x565299fc5b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=784 server | 1.257 DEBUG Acked crypto frame space=hs offset=0 length=736 server | 1.257 DEBUG Read Ok(36) bytes server | 1.257 DEBUG [Agent 0x565299f7e710] 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.257 DEBUG [Server 4cf52679a3050e167f39] TLS connection complete server | 1.257 DEBUG [pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290] Path validated Instant { tv_sec: 551, tv_nsec: 815805031 } server | 1.257 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.257 DEBUG [Crypto] application read keys installed server | 1.257 DEBUG [Server 4cf52679a3050e167f39] State change from Handshaking -> Connected server | 1.257 DEBUG [Server 4cf52679a3050e167f39] State change from Connected -> Confirmed server | 1.257 DEBUG PMTUD started with probe size 1380 server | 1.257 INFO [Server 4cf52679a3050e167f39] Connection established server | 1.257 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 551, tv_nsec: 815805031 } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=4 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 1006 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [22, 239, 126, 85, 242, 82, 228, 44], stateless_reset_token: [113, 92, 183, 233, 182, 111, 146, 215, 121, 254, 186, 15, 8, 231, 8, 86] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [144, 79, 69, 240, 152, 111, 200, 174], stateless_reset_token: [182, 22, 246, 58, 142, 185, 106, 85, 239, 29, 180, 178, 16, 76, 235, 81] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [135, 78, 179, 169, 55, 153, 92, 122], stateless_reset_token: [201, 134, 247, 189, 130, 168, 148, 105, 206, 2, 161, 47, 22, 113, 206, 247] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [132, 241, 50, 41, 34, 104, 67, 237], stateless_reset_token: [124, 167, 92, 154, 178, 34, 134, 144, 161, 15, 231, 32, 163, 201, 248, 141] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [109, 141, 182, 129, 198, 95, 9, 53], stateless_reset_token: [44, 79, 40, 123, 211, 94, 161, 237, 110, 208, 233, 232, 143, 253, 14, 243] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [68, 127, 55, 202, 248, 181, 94, 109], stateless_reset_token: [220, 42, 21, 92, 19, 244, 43, 127, 216, 210, 221, 57, 141, 182, 249, 17] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [206, 203, 30, 141, 44, 152, 145, 96], stateless_reset_token: [148, 56, 101, 64, 17, 222, 96, 26, 116, 38, 57, 13, 202, 225, 190, 225] } server | -> RX Padding { len: 781 } server | 1.257 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 551, tv_nsec: 815805031 } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.257 DEBUG Building Handshake dcid Some(CID [8]: cd0362c53e6db8a3) scid Some(CID [10]: 84a440e47176a0b157d1) server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=1 type=Handshake pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 49 server | TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] Drop packet number space hs server | 1.257 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.257 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=0 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1332 server | TX -> Ack { largest_acknowledged: 4, 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: [146, 30, 17, 224, 221, 182, 78, 188, 8, 178], stateless_reset_token: [46, 141, 183, 135, 92, 136, 146, 163, 56, 95, 37, 56, 162, 7, 25, 45] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [21, 193, 242, 131, 100, 129, 187, 68, 76, 237], stateless_reset_token: [68, 17, 120, 49, 53, 50, 72, 137, 152, 112, 144, 184, 98, 137, 120, 74] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [205, 216, 54, 157, 178, 229, 103, 86, 199, 200], stateless_reset_token: [57, 171, 145, 71, 250, 115, 93, 23, 163, 244, 121, 207, 115, 189, 157, 13] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [229, 225, 68, 139, 120, 166, 115, 106, 113, 93], stateless_reset_token: [5, 245, 25, 167, 195, 76, 183, 167, 138, 241, 148, 186, 197, 51, 60, 224] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [95, 79, 49, 22, 4, 75, 92, 55, 57, 159], stateless_reset_token: [41, 41, 69, 59, 215, 192, 43, 95, 92, 209, 0, 172, 128, 121, 110, 235] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [116, 42, 145, 45, 237, 168, 231, 189, 72, 98], stateless_reset_token: [51, 215, 133, 113, 47, 227, 162, 136, 83, 85, 88, 158, 247, 119, 67, 239] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [40, 13, 52, 103, 98, 206, 30, 107, 169, 246], stateless_reset_token: [162, 23, 204, 26, 11, 119, 120, 163, 24, 76, 150, 241, 180, 87, 43, 214] } server | TX -> Padding { len: 1041 } server | 1.257 DEBUG packet_sent this=0x565299fc5b40, pn=0, ps=1283 server | 1.257 DEBUG ECN probing: sent 2 probes server | 1.257 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.257 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.257 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=1 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.257 DEBUG packet_sent this=0x565299fc5b40, pn=1, ps=1332 server | 1.257 DEBUG ECN probing: sent 3 probes server | 1.257 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.257 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.257 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.376046ms server | 1.257 DEBUG Setting timeout of 1.376046ms server | 1.257 DEBUG [Server 4cf52679a3050e167f39] pn=5 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 50 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 1.257 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 551, tv_nsec: 836578801 } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.257 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.257 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.257 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.348094ms server | 1.257 DEBUG Setting timeout of 1.348094ms server | 1.258 DEBUG [Server 4cf52679a3050e167f39] send session ticket 406f0008e159c43a115490b80104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a84a440e47176a0b157d1100a4cf52679a3050e167f39110c000000017a8a1a8a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.258 DEBUG Path = 'jmcowrgtsp' server | 1.258 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.258 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.258 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.258 DEBUG [Server 4cf52679a3050e167f39] delay duration 274.655µs server | 1.258 DEBUG Setting timeout of 274.655µs server | 1.260 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.260 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.260 DEBUG [Server 4cf52679a3050e167f39] pn=2 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false } server | 1.260 DEBUG packet_sent this=0x565299fc5b40, pn=2, ps=1232 server | 1.260 DEBUG ECN probing: sent 4 probes server | 1.260 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.260 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.260 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.260 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.003815ms server | 1.260 DEBUG Setting timeout of 1.003815ms server | 1.260 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.260 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.260 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.260 DEBUG [Server 4cf52679a3050e167f39] delay duration 985.481µs server | 1.260 DEBUG Setting timeout of 985.481µs server | 1.262 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.262 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.262 DEBUG [Server 4cf52679a3050e167f39] pn=3 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false } server | 1.262 DEBUG packet_sent this=0x565299fc5b40, pn=3, ps=1232 server | 1.262 DEBUG ECN probing: sent 5 probes server | 1.262 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.262 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.262 DEBUG [Server 4cf52679a3050e167f39] pn=4 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false } server | 1.262 DEBUG packet_sent this=0x565299fc5b40, pn=4, ps=1232 server | 1.262 DEBUG ECN probing: sent 6 probes server | 1.262 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.262 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.262 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.262 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.788001ms server | 1.262 DEBUG Setting timeout of 1.788001ms server | 1.262 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.262 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.262 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.262 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.76586ms server | 1.262 DEBUG Setting timeout of 1.76586ms server | 1.265 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.265 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.265 DEBUG [Server 4cf52679a3050e167f39] pn=5 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false } server | 1.265 DEBUG packet_sent this=0x565299fc5b40, pn=5, ps=1232 server | 1.265 DEBUG ECN probing: sent 7 probes server | 1.265 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.265 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.265 DEBUG [Server 4cf52679a3050e167f39] pn=6 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4810, len: >>1202, fin: false } server | 1.265 DEBUG packet_sent this=0x565299fc5b40, pn=6, ps=1232 server | 1.265 DEBUG ECN probing: sent 8 probes server | 1.265 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.265 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.265 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.265 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.801877ms server | 1.265 DEBUG Setting timeout of 1.801877ms server | 1.265 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.265 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.265 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.265 DEBUG [Server 4cf52679a3050e167f39] delay duration 1.780467ms server | 1.265 DEBUG Setting timeout of 1.780467ms server | 1.268 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.268 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.268 DEBUG [Server 4cf52679a3050e167f39] pn=7 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 6012, len: >>1202, fin: false } server | 1.268 DEBUG packet_sent this=0x565299fc5b40, pn=7, ps=1232 server | 1.268 DEBUG ECN probing: sent 9 probes server | 1.268 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.268 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.268 DEBUG [Server 4cf52679a3050e167f39] pn=8 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 7214, len: >>1202, fin: false } server | 1.268 DEBUG packet_sent this=0x565299fc5b40, pn=8, ps=1232 server | 1.268 DEBUG ECN probing: sent 10 probes server | 1.268 DEBUG ECN probing concluded with 10 probes sent server | 1.268 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1081, pto: None, probe: EnumSet(), paced: false } server | 1.268 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.268 DEBUG [Server 4cf52679a3050e167f39] pn=9 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 1081 server | TX -> Stream { stream_id: 0, offset: 8416, len: >>1051, fin: false } server | 1.268 DEBUG packet_sent this=0x565299fc5b40, pn=9, ps=1081 server | 1.269 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.269 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG [Server 4cf52679a3050e167f39] delay duration 8.82121ms server | 1.269 DEBUG Setting timeout of 8.82121ms server | 1.269 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.269 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.269 DEBUG [Server 4cf52679a3050e167f39] delay duration 8.803327ms server | 1.269 DEBUG Setting timeout of 8.803327ms server | 1.279 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.279 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.279 DEBUG [Server 4cf52679a3050e167f39] pn=10 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 32 server | TX -> Ack { largest_acknowledged: 5, ack_delay: 2665, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.279 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.279 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.279 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.279 DEBUG [Server 4cf52679a3050e167f39] delay duration 109.176571ms server | 1.279 DEBUG Setting timeout of 109.176571ms server | 1.279 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.279 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.279 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.279 DEBUG [Server 4cf52679a3050e167f39] delay duration 109.154289ms server | 1.279 DEBUG Setting timeout of 109.154289ms server | 1.290 DEBUG [Server 4cf52679a3050e167f39] pn=6 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 12, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.290 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=1] server | 1.290 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 1.290 WARN ECN validation failed, no ECN counts in ACK frame server | 1.290 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] slow start += 2615 server | 1.290 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615 server | 1.290 DEBUG PMTUD probe of size 1380 succeeded server | 1.290 DEBUG PMTUD started with probe size 1420 server | 1.290 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.290 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.290 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.290 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.290 DEBUG CRYPTO for ap offset=0, len=321 server | 1.290 DEBUG [Server 4cf52679a3050e167f39] pn=11 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 1372 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 9467, len: 773, fin: true } server | TX -> Crypto { offset: 0, len: 321 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 198, 11, 38, 14, 29, 239, 138, 231, 108, 231, 93, 229, 134, 210, 22, 149, 26, 175, 145, 13, 123, 117, 165, 147, 56, 5, 123, 170, 57, 37, 21, 208, 218, 6, 72, 229] } server | TX -> Padding { len: 196 } server | 1.290 DEBUG packet_sent this=0x565299fc5b40, pn=11, ps=1372 server | 1.290 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.290 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.290 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.290 DEBUG [Server 4cf52679a3050e167f39] delay duration 109.574828ms server | 1.290 DEBUG Setting timeout of 109.574828ms server | 1.290 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.290 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.290 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.290 DEBUG [Server 4cf52679a3050e167f39] delay duration 109.541266ms server | 1.290 DEBUG Setting timeout of 109.541266ms server | 1.292 DEBUG [Server 4cf52679a3050e167f39] pn=7 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 35 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 152, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.292 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=2] server | 1.292 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.292 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9845/16167 ssthresh 18446744073709551615] slow start += 1232 server | 1.292 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9845/16167 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=9845, cwnd=16167, state=SlowStart, new_acked=1232 server | 1.292 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.292 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.292 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.292 DEBUG [Server 4cf52679a3050e167f39] delay duration 99.443879ms server | 1.292 DEBUG Setting timeout of 99.443879ms server | 1.292 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.292 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.292 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.292 DEBUG [Server 4cf52679a3050e167f39] delay duration 99.380451ms server | 1.292 DEBUG Setting timeout of 99.380451ms server | 1.294 DEBUG [Server 4cf52679a3050e167f39] pn=8 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 13, first_ack_range: 4, ack_ranges: [], ecn_count: None } server | 1.294 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=4] server | 1.294 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.294 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7381/18631 ssthresh 18446744073709551615] slow start += 2464 server | 1.294 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7381/18631 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=7381, cwnd=18631, state=SlowStart, new_acked=2464 server | 1.294 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.294 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.294 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.294 DEBUG [Server 4cf52679a3050e167f39] delay duration 90.868694ms server | 1.294 DEBUG Setting timeout of 90.868694ms server | 1.294 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.294 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.294 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.294 DEBUG [Server 4cf52679a3050e167f39] delay duration 90.804274ms server | 1.294 DEBUG Setting timeout of 90.804274ms server | 1.298 DEBUG [Server 4cf52679a3050e167f39] pn=9 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 7, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 1.298 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=6] server | 1.298 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.298 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4917/21095 ssthresh 18446744073709551615] slow start += 2464 server | 1.298 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4917/21095 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=4917, cwnd=21095, state=SlowStart, new_acked=2464 server | 1.298 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.298 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.298 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.298 DEBUG [Server 4cf52679a3050e167f39] delay duration 82.254095ms server | 1.298 DEBUG Setting timeout of 82.254095ms server | 1.298 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.298 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.298 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.298 DEBUG [Server 4cf52679a3050e167f39] delay duration 82.195255ms server | 1.298 DEBUG Setting timeout of 82.195255ms server | 1.301 DEBUG [Server 4cf52679a3050e167f39] pn=10 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 34 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 7, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 1.301 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=8] server | 1.301 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.301 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2453/23559 ssthresh 18446744073709551615] slow start += 2464 server | 1.301 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2453/23559 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=2453, cwnd=23559, state=SlowStart, new_acked=2464 server | 1.301 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.301 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.301 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.301 DEBUG [Server 4cf52679a3050e167f39] delay duration 74.377226ms server | 1.301 DEBUG Setting timeout of 74.377226ms server | 1.301 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.301 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.301 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.301 DEBUG [Server 4cf52679a3050e167f39] delay duration 74.317014ms server | 1.301 DEBUG Setting timeout of 74.317014ms server | 1.303 DEBUG [Server 4cf52679a3050e167f39] pn=11 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 35 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 146, first_ack_range: 9, ack_ranges: [], ecn_count: None } server | 1.303 DEBUG [Server 4cf52679a3050e167f39] Rx ACK space=ap, ranges=[0..=9] server | 1.303 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=9 server | 1.303 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] slow start += 1081 server | 1.303 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] on_packets_acked this=0x565299fc5b40, limited=0, bytes_in_flight=1372, cwnd=24640, state=SlowStart, new_acked=1081 server | 1.303 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.303 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.303 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.303 DEBUG [Server 4cf52679a3050e167f39] delay duration 67.88594ms server | 1.303 DEBUG Setting timeout of 67.88594ms server | 1.303 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.303 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.303 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.303 DEBUG [Server 4cf52679a3050e167f39] delay duration 67.814347ms server | 1.303 DEBUG Setting timeout of 67.814347ms server | 1.323 DEBUG [Server 4cf52679a3050e167f39] pn=12 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 33 server | -> RX ConnectionClose { error_code: Application(256), frame_type: 0, reason_phrase: "" } server | 1.323 INFO [Server 4cf52679a3050e167f39] ConnectionClose received. Error code: Application(256) frame type 0 reason server | 1.323 DEBUG [Server 4cf52679a3050e167f39] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(256)), timeout: Instant { tv_sec: 552, tv_nsec: 124236136 } } server | 1.323 DEBUG [pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290] Path validated Instant { tv_sec: 551, tv_nsec: 881825756 } server | 1.323 DEBUG [Server 4cf52679a3050e167f39] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.323 DEBUG Building Short dcid Some(CID [8]: cd0362c53e6db8a3) server | 1.323 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 551, tv_nsec: 881825756 } server | 1.323 DEBUG [Server 4cf52679a3050e167f39] pn=12 type=Short pri-path:cd0362c53e6db8a3 [::]:443->[::ffff:193.167.0.100]:44290 IpTos(Cs0, NotEct) len 35 server | TX -> Ack { largest_acknowledged: 12, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.323 DEBUG Setting timeout of 242.278234ms server | 1.323 DEBUG Setting timeout of 242.261834ms server | 1.566 DEBUG [Server 4cf52679a3050e167f39] State change from Draining { error: Transport(PeerApplicationError(256)), timeout: Instant { tv_sec: 552, tv_nsec: 124236136 } } -> Closed(Transport(PeerApplicationError(256))) server | 1.566 INFO Closing timer expired client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 12:25:20,568 Using the client's key log file. 2025-04-30 12:25:20,576 2025-04-30 12:25:20,577 Using the client's key log file. 2025-04-30 12:25:20,577 Using the client's key log file. 2025-04-30 12:25:20,584 2025-04-30 12:25:20,585 Using the client's key log file. 2025-04-30 12:25:20,862 At least one QUIC packet could not be decrypted 2025-04-30 12:25:20,862 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: 7 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: 44290 Length: 1340 Checksum: 0xbfa4 [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 71.942000 milliseconds Time since previous frame: 634.000 microseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 49 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: cd0362c53e6db8a3 Source Connection ID Length: 10 Source Connection ID: 84a440e47176a0b157d1 Length: 22 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: 05091ccbe016abe70c37e78c430f3c5b961c444e4c1a Layer QUIC : Packet Length: 1283 QUIC Short Header DCID=cd0362c53e6db8a3 0... .... = Header Form: Short Header (0) .1.. .... = Fixed Bit: True ..1. .... = Spin Bit: True Destination Connection ID: cd0362c53e6db8a3 Remaining Payload […]: d224a144ae02c3bcdbbef1c6c2b0f3fd979c3c011dcd0535df9f44cdae831ba506655a9f11f5cb88928d10057a8a254ab1465eefc9b1bb345a944ef479025e19b227eb77605feadba34e98e559cf5b0781b7085a9a3e4e3c18a23df3fb0e99a9cb61f4d09e58a516fa99eb 2025-04-30 12:25:21,136 At least one QUIC packet could not be decrypted 2025-04-30 12:25:21,136 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: 7 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: 44290 Length: 1340 Checksum: 0xbfa4 [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 71.942000 milliseconds Time since previous frame: 634.000 microseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 49 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: cd0362c53e6db8a3 Source Connection ID Length: 10 Source Connection ID: 84a440e47176a0b157d1 Length: 22 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: 05091ccbe016abe70c37e78c430f3c5b961c444e4c1a Layer QUIC : Packet Length: 1283 QUIC Short Header DCID=cd0362c53e6db8a3 0... .... = Header Form: Short Header (0) .1.. .... = Fixed Bit: True ..1. .... = Spin Bit: True Destination Connection ID: cd0362c53e6db8a3 Remaining Payload […]: d224a144ae02c3bcdbbef1c6c2b0f3fd979c3c011dcd0535df9f44cdae831ba506655a9f11f5cb88928d10057a8a254ab1465eefc9b1bb345a944ef479025e19b227eb77605feadba34e98e559cf5b0781b7085a9a3e4e3c18a23df3fb0e99a9cb61f4d09e58a516fa99eb 2025-04-30 12:25:21,137 Check of downloaded files succeeded. 2025-04-30 12:25:21,417 At least one QUIC packet could not be decrypted 2025-04-30 12:25:21,417 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: 3 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: 44290 Length: 1340 Checksum: 0xbfa4 [unverified] Checksum Status: Unverified Stream index: 0 Stream Packet Number: 7 Timestamps Time since first frame: 109.348000 milliseconds Time since previous frame: 32.601000 milliseconds UDP payload (1332 bytes) Layer QUIC : QUIC Connection information Connection Number: 0 Packet Length: 49 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: cd0362c53e6db8a3 Source Connection ID Length: 10 Source Connection ID: 84a440e47176a0b157d1 Length: 22 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: 05091ccbe016abe70c37e78c430f3c5b961c444e4c1a Layer QUIC : Packet Length: 1283 QUIC Short Header DCID=cd0362c53e6db8a3 0... .... = Header Form: Short Header (0) .1.. .... = Fixed Bit: True ..1. .... = Spin Bit: True Destination Connection ID: cd0362c53e6db8a3 Remaining Payload […]: d224a144ae02c3bcdbbef1c6c2b0f3fd979c3c011dcd0535df9f44cdae831ba506655a9f11f5cb88928d10057a8a254ab1465eefc9b1bb345a944ef479025e19b227eb77605feadba34e98e559cf5b0781b7085a9a3e4e3c18a23df3fb0e99a9cb61f4d09e58a516fa99eb 2025-04-30 12:25:21,701 Check of Retry succeeded. Token used: 52657472790100738709f05d3d6c755c05d6fd47adc9580e930d6a4a54da0aaaea1dbc8ab79758b9fbddc8222aa40fadcff981