2025-04-30 12:32:40,080 Generated random file: qgqejdakuc of size: 10240
2025-04-30 12:32:40,080 Requests: https://server4:443/qgqejdakuc
2025-04-30 12:32:40,138 
2025-04-30 12:32:40,139 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_1711yq2g/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_b1b36pdo/ DOWNLOADS=/tmp/download_1rtj8aw7/ SERVER_LOGS=/tmp/logs_server_z48jhemo CLIENT_LOGS=/tmp/logs_client_1vd6susk SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=peterdoornbosch/kwik_n_flupke-interop SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/qgqejdakuc"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 12:32:54,183  Container sim  Created
 Container client  Recreate
 Container server  Recreate
 Container server  Recreated
 Container client  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
client  | tx-tcp-ecn-segmentation: off [not requested]
client  | tx-tcp-mangleid-segmentation: off [not requested]
client  | tx-tcp6-segmentation: off [not requested]
client  | tx-udp-segmentation: off [not requested]
client  | tx-checksum-sctp: off
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
server  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + '[' -n retry ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.J2vrpU6vol
server  | + mkdir -p /neqo/db
server  | + certutil -N -d sql:/neqo/db --empty-password
server  | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.J2vrpU6vol
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.J2vrpU6vol -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  |             0f:34:2d:53:0e:0f:dd:c7:50:4d:3d:90:29:ab:d6:3f:
server  |             52:58:ab:8c
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:32:40 2025
server  |             Not After : Sat May 10 12:32:40 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:cf:5e:7f:69:10:57:6f:fa:d1:f0:e6:f6:e8:18:49:
server  |                     99:d6:82:08:53:5e:4b:a7:69:51:84:67:24:ad:89:01:
server  |                     49:a0:63:4a:3d:1d:01:2c:82:b2:60:36:07:03:36:d5:
server  |                     0e:ef:25:9f:70:f7:43:7f:46:36:30:7c:f0:4e:55:ec:
server  |                     65
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  |                 23:0b:eb:ba:5b:7a:37:19:5e:67:fa:87:b7:38:0c:57:
server  |                 14:24:eb:75
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 60:45:49:fd:e3:61:8c:35:8e:83:72:f0:59:a0:1b:dd:
server  |                 25:2e:0e:29
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:20:4e:76:25:60:62:0d:dc:06:2e:35:25:61:
server  |         e7:72:bd:a5:b0:79:91:d2:44:04:c3:2f:44:5e:52:6b:
server  |         db:f7:be:fd:02:21:00:85:ea:36:ef:1d:09:6b:c1:f9:
server  |         77:80:47:2a:dd:4b:3c:89:17:dd:0f:88:f2:8e:4c:d4:
server  |         81:47:6e:c7:65:96:f9
server  |     Fingerprint (SHA-256):
server  |         A9:9A:53:8C:0D:C3:2D:12:95:1A:0A:63:0D:25:67:48:37:81:7C:9D:EC:B7:1D:8B:40:1B:77:17:1F:D9:9E:12
server  |     Fingerprint (SHA1):
server  |         45:F4:86:5C:94:3C:01:77:FA:47:6D:05:F1:72:BC:3B:C7:49:76:55
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
client  | Certificate was added to keystore
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | 0.726 DEBUG [Server] Unsupported version: 57414954
server  | 0.726 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52096 IpTos(Cs0, NotEct) len 15
sim     | server:443 is available after 1.010938571s
server  | 0.727 DEBUG [Server] Unsupported version: 57414954
server  | 0.727 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52096 IpTos(Cs0, NotEct) len 15
server  | 0.727 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.727 DEBUG [Server] Unsupported version: 57414954
server  | 0.727 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52096 IpTos(Cs0, NotEct) len 15
server  | 0.727 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | 32:42.342 Creating connection with server4:443 with v1
client  | 32:42.426 Original destination connection id: af9d5dfc05537e45 (scid: f9c10ec87671fd06)
client  |           >- CryptoStream[I|ClientHello]
server  | 1.835 DEBUG [Server] Handle initial
server  | 1.835 INFO AddressValidation: no token; validating
server  | 1.835 INFO [Server] Send retry for CID [8]: af9d5dfc05537e45
server  | 1.835 DEBUG [Server] type=Retry path:af9d5dfc05537e45 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 92
client  | 32:42.581 -> Packet I|0|L|1200|2  Token=[] CryptoFrame[0,257] Padding(896)
client  | 32:42.619 <- (1) Packet I|-|R|92| Retry Token (51): 52657472790100f1ea755b95499f494445d9c6e3b015fbefcabb8b4277a1602c53b53e0aaa241e86d16821a87b7091db10713b
client  | 32:42.645 -> Packet I|1|L|1200|2  Token=52657472790100f1ea755b95499f494445d9c6e3b015fbefcabb8b4277a1602c53b53e0aaa241e86d16821a87b7091db10713b CryptoFrame[0,257] Padding(843)
server  | 1.893 DEBUG [Server] Handle initial
server  | 1.893 INFO AddressValidation: valid Retry token for af9d5dfc05537e45
server  | 1.893 INFO [Server] Accept connection CID [8]: af9d5dfc05537e45
server  | 1.894 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.895 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.895 INFO [Server ...] Received valid Initial packet with scid CID [8]: f9c10ec87671fd06 dcid CID [10]: 87200c3709b8490173f9
server  | 1.895 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=87200c3709b8490173f9
server  | 1.895 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.895 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.895 DEBUG [Server 87200c3709b8490173f9] State change from Init -> WaitInitial
server  | 1.895 DEBUG [Server 87200c3709b8490173f9] pn=1 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 1200
server  |   -> RX Crypto { offset: 0, len: 257 }
server  |   -> RX Padding { len: 843 }
server  | 1.895 DEBUG Read Ok(257) bytes
server  | 1.895 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.896 DEBUG Read secret available for Handshake: SymKey [32]: bda8685f0a5cd75eabcb03349f01a64c04f1736d3a6f56a88e8169aa2204ee3a
server  | 1.896 DEBUG Write secret available for Handshake: SymKey [32]: 307f57052288e897b882324f3286230266fa6df481010119b5b5b4d6c4aa4bce
server  | 1.896 DEBUG Writing transport parameters, msg=8
server  | 1.897 DEBUG Read secret available for ApplicationData: SymKey [32]: e3ba1b92afcd5946a68f880eaab7c3b48e809e3817b09d6f501b21d313da297e
server  | 1.897 DEBUG Write secret available for ApplicationData: SymKey [32]: 4e9899145c4865b14ed5967b253294e4ff023deee87d664f53dec38bba3f0340
server  | 1.897 DEBUG [Agent 0x55dc8d8d0710] state -> InProgress
server  | 1.897 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.897 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.897 DEBUG [Crypto] Handshake keys installed
server  | 1.897 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.897 DEBUG [Crypto] Application write key installed
server  | 1.897 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 108260393 }
server  | 1.897 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:51025] Make permanent
server  | 1.897 DEBUG [unv-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025] set as primary path
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] State change from WaitInitial -> Handshaking
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.897 DEBUG Building Initial dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG CRYPTO for in offset=0, len=123
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] pn=0 type=Initial pri-unv-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 177
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   TX -> Crypto { offset: 0, len: 123 }
server  | 1.897 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG CRYPTO for hs offset=0, len=732
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] pn=0 type=Handshake pri-unv-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 957
server  |   TX -> Crypto { offset: 0, len: 732 }
server  | 1.897 DEBUG packet_sent this=0x55dc8d917b40, pn=0, ps=780
server  | 1.897 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] pad Initial from 957 to PLPMTU 1232
server  | 1.897 DEBUG packet_sent this=0x55dc8d917b40, pn=0, ps=452
server  | 1.897 DEBUG ECN probing: sent 1 probes
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.897 DEBUG Building Initial dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 1.897 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] delay duration 296.45566ms
server  | 1.897 DEBUG Setting timeout of 296.45566ms
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.897 DEBUG Building Initial dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.897 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 1.897 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.897 DEBUG [Server 87200c3709b8490173f9] delay duration 296.417168ms
server  | 1.897 DEBUG Setting timeout of 296.417168ms
client  | 32:42.681 <- (2) Packet I|0|L|177|2  Token=[] AckFrame[1|?0] CryptoFrame[0,123]
client  |           -< CryptoStream[I|ServerHello]
client  | 32:42.681 <- (2) Packet H|0|L|780|1  CryptoFrame[0,732]
client  | 32:42.714 -> Packet I|2|L|1201|2  Token=52657472790100f1ea755b95499f494445d9c6e3b015fbefcabb8b4277a1602c53b53e0aaa241e86d16821a87b7091db10713b AckFrame[0|?0] Padding(1100)
client  | 32:42.731 - unsupported transport parameter 0x2ab2, size 0 (grease-quic-bit)
client  | 32:42.731 - unsupported transport parameter 0xff02de1a, size 2 (delayed-ack)
server  | 1.963 DEBUG [Server 87200c3709b8490173f9] pn=2 type=Initial pri-unv-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 1201
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   -> RX Padding { len: 1100 }
server  | 1.964 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=in, ranges=[0..=0]
server  | 1.964 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.964 DEBUG on_packets_acked this=0x55dc8d917b40, limited=1, bytes_in_flight=780, cwnd=12320, state=SlowStart, new_acked=452
server  | 1.964 DEBUG Acked crypto frame space=in offset=0 length=123
server  | 1.964 DEBUG [pri-unv-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025] Path validated Instant { tv_sec: 521, tv_nsec: 178314416 }
server  | 1.964 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.964 DEBUG Building Initial dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.964 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.964 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 1.964 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.964 DEBUG [Server 87200c3709b8490173f9] delay duration 140.108044ms
server  | 1.964 DEBUG Setting timeout of 140.108044ms
server  | 1.964 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.964 DEBUG Building Initial dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.964 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 1.964 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 1.964 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.964 DEBUG [Server 87200c3709b8490173f9] delay duration 139.940211ms
server  | 1.964 DEBUG Setting timeout of 139.940211ms
client  |           >- CryptoStream[H|Finished]
client  | 32:42.755 -> Packet H|0|L|82|1  CryptoFrame[0,36]
client  |           -< CryptoStream[H|EncryptedExtensions,Certificate,CertificateVerify,Finished]
client  | 32:42.757 -> Packet H|1|L|48|1  AckFrame[0|?0]
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] Drop packet number space in
server  | 2.003 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] pn=0 type=Handshake pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 82
server  |   -> RX Crypto { offset: 0, len: 36 }
server  | 2.003 DEBUG Read Ok(36) bytes
server  | 2.003 DEBUG [Agent 0x55dc8d8d0710] 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  | 2.003 DEBUG [Server 87200c3709b8490173f9] TLS connection complete
server  | 2.003 DEBUG [pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025] Path validated Instant { tv_sec: 521, tv_nsec: 217376875 }
server  | 2.003 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 2.003 DEBUG [Crypto] application read keys installed
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] State change from Handshaking -> Connected
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] State change from Connected -> Confirmed
server  | 2.003 DEBUG PMTUD started with probe size 1380
server  | 2.003 INFO [Server 87200c3709b8490173f9] Connection established
server  | 2.003 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 217376875 }
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.003 DEBUG Building Handshake dcid Some(CID [8]: f9c10ec87671fd06) scid Some(CID [10]: d582a0dde437c9796312)
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] pn=1 type=Handshake pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 49
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] Drop packet number space hs
server  | 2.003 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 2.003 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] pn=0 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [106, 118, 35, 60, 137, 77, 7, 117, 32, 248], stateless_reset_token: [84, 200, 24, 222, 116, 248, 227, 231, 7, 186, 199, 68, 214, 64, 10, 49] }
server  |   TX -> Padding { len: 1226 }
server  | 2.003 DEBUG packet_sent this=0x55dc8d917b40, pn=0, ps=1283
server  | 2.003 DEBUG ECN probing: sent 2 probes
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.003 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.003 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] pn=1 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1305 }
server  | 2.003 DEBUG packet_sent this=0x55dc8d917b40, pn=1, ps=1332
server  | 2.003 DEBUG ECN probing: sent 3 probes
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.003 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.003 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.003 DEBUG [Server 87200c3709b8490173f9] delay duration 3.355353ms
server  | 2.003 DEBUG Setting timeout of 3.355353ms
server  | 2.004 DEBUG [Server 87200c3709b8490173f9] send session ticket 406f0008af9d5dfc05537e450104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0ad582a0dde437c9796312100a87200c3709b8490173f9110c00000001eaba5a4a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 2.004 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.004 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.004 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.004 DEBUG [Server 87200c3709b8490173f9] delay duration 2.237982ms
server  | 2.004 DEBUG Setting timeout of 2.237982ms
server  | 2.004 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1
server  | 2.005 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.005 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.005 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.005 DEBUG [Server 87200c3709b8490173f9] delay duration 1.96816ms
server  | 2.005 DEBUG Setting timeout of 1.96816ms
server  | 2.005 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.005 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.005 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.005 DEBUG [Server 87200c3709b8490173f9] delay duration 1.931131ms
server  | 2.005 DEBUG Setting timeout of 1.931131ms
client  | 32:42.763 -> Packet A|0|S0|d582a0dde437c9796312|49|1  StreamFrame[0(CIB),0,17,fin]
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.008 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.008 DEBUG CRYPTO for ap offset=0, len=321
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] pn=2 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 396
server  |   TX -> Crypto { offset: 0, len: 321 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 99, 78, 116, 153, 127, 233, 142, 212, 163, 223, 158, 216, 20, 241, 88, 101, 9, 103, 246, 163, 92, 148, 80, 130, 102, 220, 124, 96, 61, 181, 222, 22, 115, 121, 88, 83] }
server  | 2.008 DEBUG packet_sent this=0x55dc8d917b40, pn=2, ps=396
server  | 2.008 DEBUG ECN probing: sent 4 probes
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.008 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.008 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] delay duration 234.992371ms
server  | 2.008 DEBUG Setting timeout of 234.992371ms
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.008 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.008 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.008 DEBUG [Server 87200c3709b8490173f9] delay duration 234.966152ms
server  | 2.008 DEBUG Setting timeout of 234.966152ms
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] pn=0 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 49
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  | 2.010 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 245035720 }
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.010 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.010 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] delay duration 20ms
server  | 2.010 DEBUG Setting timeout of 20ms
server  | 2.010 DEBUG Path = 'qgqejdakuc'
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.010 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] pn=3 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false }
server  | 2.010 DEBUG packet_sent this=0x55dc8d917b40, pn=3, ps=1232
server  | 2.010 DEBUG ECN probing: sent 5 probes
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.010 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] pn=4 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false }
server  | 2.010 DEBUG packet_sent this=0x55dc8d917b40, pn=4, ps=1232
server  | 2.010 DEBUG ECN probing: sent 6 probes
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.010 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.010 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.010 DEBUG [Server 87200c3709b8490173f9] delay duration 3.4379ms
server  | 2.011 DEBUG Setting timeout of 3.4379ms
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.015 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] pn=5 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false }
server  | 2.015 DEBUG packet_sent this=0x55dc8d917b40, pn=5, ps=1232
server  | 2.015 DEBUG ECN probing: sent 7 probes
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.015 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.015 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] delay duration 2.751235ms
server  | 2.015 DEBUG Setting timeout of 2.751235ms
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.015 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.015 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.015 DEBUG [Server 87200c3709b8490173f9] delay duration 2.729705ms
server  | 2.015 DEBUG Setting timeout of 2.729705ms
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.019 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] pn=6 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false }
server  | 2.019 DEBUG packet_sent this=0x55dc8d917b40, pn=6, ps=1232
server  | 2.019 DEBUG ECN probing: sent 8 probes
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.019 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.019 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] delay duration 2.060881ms
server  | 2.019 DEBUG Setting timeout of 2.060881ms
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.019 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.019 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.019 DEBUG [Server 87200c3709b8490173f9] delay duration 2.039471ms
server  | 2.019 DEBUG Setting timeout of 2.039471ms
client  | 32:42.788 <- (3) Packet H|1|L|49|1  AckFrame[0|?0]
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.022 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] pn=7 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4810, len: >>1202, fin: false }
server  | 2.022 DEBUG packet_sent this=0x55dc8d917b40, pn=7, ps=1232
server  | 2.022 DEBUG ECN probing: sent 9 probes
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.022 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.022 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] delay duration 2.363753ms
server  | 2.022 DEBUG Setting timeout of 2.363753ms
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.022 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.022 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.022 DEBUG [Server 87200c3709b8490173f9] delay duration 2.343105ms
server  | 2.022 DEBUG Setting timeout of 2.343105ms
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.026 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] pn=8 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 6012, len: >>1202, fin: false }
server  | 2.026 DEBUG packet_sent this=0x55dc8d917b40, pn=8, ps=1232
server  | 2.026 DEBUG ECN probing: sent 10 probes
server  | 2.026 DEBUG ECN probing concluded with 10 probes sent
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.026 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.026 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] delay duration 1.530982ms
server  | 2.026 DEBUG Setting timeout of 1.530982ms
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.026 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.026 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 2.026 DEBUG [Server 87200c3709b8490173f9] delay duration 1.505214ms
server  | 2.026 DEBUG Setting timeout of 1.505214ms
client  | 32:42.788 <- (3) Packet A|0|S0|f9c10ec87671fd06|1283|3  HandshakeDoneFrame[] NewConnectionIdFrame[1,<0|6a76233c894d077520f8|54c818de74f8e3e707bac744d6400a31] Padding(1226)
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] pn=9 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 7214, len: >>1202, fin: false }
server  | 2.029 DEBUG packet_sent this=0x55dc8d917b40, pn=9, ps=1232
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 685, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] pn=10 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 685
server  |   TX -> Stream { stream_id: 0, offset: 8416, len: >>655, fin: false }
server  | 2.029 DEBUG packet_sent this=0x55dc8d917b40, pn=10, ps=685
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.029 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] delay duration 1.261477ms
server  | 2.029 DEBUG Setting timeout of 1.261477ms
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.029 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG [Server 87200c3709b8490173f9] delay duration 1.240478ms
server  | 2.029 DEBUG Setting timeout of 1.240478ms
client  | 32:42.789 <- (4) Packet A|1|S0|f9c10ec87671fd06|1332|2  PingFrame[] Padding(1305)
server  | 2.031 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.031 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.031 DEBUG [Server 87200c3709b8490173f9] pn=11 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 32
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 2608, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 2.031 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.031 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.031 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.031 DEBUG [Server 87200c3709b8490173f9] delay duration 232.523273ms
server  | 2.032 DEBUG Setting timeout of 232.523273ms
server  | 2.032 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.032 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 2.032 DEBUG [Server 87200c3709b8490173f9] delay duration 232.347255ms
server  | 2.032 DEBUG Setting timeout of 232.347255ms
client  | 32:42.800 -> Packet A|1|S0|d582a0dde437c9796312|34|1  AckFrame[1-0|?3]
client  | 32:42.791 <- (5) Packet A|2|S0|f9c10ec87671fd06|396|2  CryptoFrame[0,321] NewTokenFrame[ad9a8b8d860100634e74997fe98ed4a3df9ed814f158650967f6a35c94508266dc7c603db5de1673795853]
client  |           -< CryptoStream[A|NewSessionTicket]
client  | 32:42.795 <- (6) Packet A|3|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),0,1204]
client  | 32:42.796 <- (7) Packet A|4|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),1204,1202]
client  | 32:42.799 <- (8) Packet A|5|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),2406,1202]
client  | 32:42.808 -> Packet A|2|S0|d582a0dde437c9796312|34|1  AckFrame[4-0|?2]
client  | 32:42.804 <- (9) Packet A|6|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),3608,1202]
client  | 32:42.806 <- (10) Packet A|7|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),4810,1202]
client  | 32:42.810 -> Packet A|3|S0|d582a0dde437c9796312|34|1  AckFrame[7-0|?1]
client  | 32:42.811 <- (11) Packet A|8|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),6012,1202]
client  | 32:42.813 <- (12) Packet A|9|S0|f9c10ec87671fd06|1232|1  StreamFrame[0(CIB),7214,1202]
client  | 32:42.814 <- (13) Packet A|10|S0|f9c10ec87671fd06|685|1  StreamFrame[0(CIB),8416,655]
client  | 32:42.815 <- (14) Packet A|11|S0|f9c10ec87671fd06|32|1  AckFrame[0|?20]
client  | 32:42.815 -> Packet A|4|S0|d582a0dde437c9796312|34|1  AckFrame[9-0|?2]
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] pn=1 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 375, first_ack_range: 1, ack_ranges: [], ecn_count: None }
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=1]
server  | 2.050 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1
server  | 2.050 WARN ECN validation failed, no ECN counts in ACK frame
server  | 2.050 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] slow start += 2615
server  | 2.050 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615
server  | 2.050 DEBUG PMTUD probe of size 1380 succeeded
server  | 2.050 DEBUG PMTUD started with probe size 1420
server  | 2.050 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.050 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.050 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] pn=12 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 1372
server  |   TX -> Ping
server  |   TX -> Stream { stream_id: 0, offset: 9071, len: 1169, fin: true }
server  |   TX -> Padding { len: 170 }
server  | 2.050 DEBUG packet_sent this=0x55dc8d917b40, pn=12, ps=1372
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.050 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.050 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] delay duration 220.326984ms
server  | 2.050 DEBUG Setting timeout of 220.326984ms
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.050 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.050 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.050 DEBUG [Server 87200c3709b8490173f9] delay duration 220.284946ms
server  | 2.050 DEBUG Setting timeout of 220.284946ms
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] pn=2 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 250, first_ack_range: 4, ack_ranges: [], ecn_count: None }
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=4]
server  | 2.056 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4
server  | 2.056 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8217/17795 ssthresh 18446744073709551615] slow start += 2860
server  | 2.056 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8217/17795 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=8217, cwnd=17795, state=SlowStart, new_acked=2860
server  | 2.056 DEBUG Acked crypto frame space=ap offset=0 length=321
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.056 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.056 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] delay duration 201.881344ms
server  | 2.056 DEBUG Setting timeout of 201.881344ms
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.056 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.056 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.056 DEBUG [Server 87200c3709b8490173f9] delay duration 201.799882ms
server  | 2.056 DEBUG Setting timeout of 201.799882ms
server  | 2.057 DEBUG [Server 87200c3709b8490173f9] pn=3 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 7, ack_delay: 125, first_ack_range: 7, ack_ranges: [], ecn_count: None }
server  | 2.057 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=7]
server  | 2.057 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=7
server  | 2.057 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4521/21491 ssthresh 18446744073709551615] slow start += 3696
server  | 2.057 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4521/21491 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=4521, cwnd=21491, state=SlowStart, new_acked=3696
server  | 2.057 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.057 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.057 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.057 DEBUG [Server 87200c3709b8490173f9] delay duration 195.671951ms
server  | 2.058 DEBUG Setting timeout of 195.671951ms
server  | 2.058 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.058 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.058 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.058 DEBUG [Server 87200c3709b8490173f9] delay duration 195.60191ms
server  | 2.058 DEBUG Setting timeout of 195.60191ms
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] pn=4 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 9, ack_delay: 250, first_ack_range: 9, ack_ranges: [], ecn_count: None }
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=9]
server  | 2.062 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=9
server  | 2.062 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2057/23955 ssthresh 18446744073709551615] slow start += 2464
server  | 2.062 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2057/23955 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=2057, cwnd=23955, state=SlowStart, new_acked=2464
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.062 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.062 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] delay duration 185.824211ms
server  | 2.062 DEBUG Setting timeout of 185.824211ms
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.062 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.062 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.062 DEBUG [Server 87200c3709b8490173f9] delay duration 185.725627ms
server  | 2.062 DEBUG Setting timeout of 185.725627ms
client  | 32:42.834 <- (15) Packet A|12|S0|f9c10ec87671fd06|1372|3  PingFrame[] StreamFrame[0(CIB),9071,1169,fin] Padding(170)
client  | 32:42.835 -> Packet A|5|S0|d582a0dde437c9796312|34|1  AckFrame[11-0|?20]
client  | Get requested finished in 0.41 sec (0.02 MB/s) : tech.kwik.h09.client.HttpResponseImpl@2ddc8ecb
client  | 32:42.844 Closing ClientConnection[af9d5dfc05537e45/f9c10ec87671fd06(V1) with server4/193.167.100.100:443] (reason: ImmediateClose)
client  | 32:42.846 -> Packet A|6|S0|d582a0dde437c9796312|38|2  ConnectionCloseFrame[0|0|] AckFrame[12-0|?10]
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] pn=5 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 11, ack_delay: 2500, first_ack_range: 11, ack_ranges: [], ecn_count: None }
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=11]
server  | 2.082 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=11
server  | 2.082 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] slow start += 685
server  | 2.082 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/24640 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=1372, cwnd=24640, state=SlowStart, new_acked=685
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.082 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.082 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] delay duration 141.823662ms
server  | 2.082 DEBUG Setting timeout of 141.823662ms
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.082 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.082 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.082 DEBUG [Server 87200c3709b8490173f9] delay duration 141.67262ms
server  | 2.082 DEBUG Setting timeout of 141.67262ms
server  | 2.094 DEBUG [Server 87200c3709b8490173f9] pn=6 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 38
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  |   -> RX Ack { largest_acknowledged: 12, ack_delay: 1250, first_ack_range: 12, ack_ranges: [], ecn_count: None }
server  | 2.094 INFO [Server 87200c3709b8490173f9] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 2.094 DEBUG [Server 87200c3709b8490173f9] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 521, tv_nsec: 832033205 } }
server  | 2.094 DEBUG [Server 87200c3709b8490173f9] Rx ACK space=ap, ranges=[0..=12]
server  | 2.094 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12
server  | 2.094 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] slow start += 1372
server  | 2.094 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/26012 ssthresh 18446744073709551615] on_packets_acked this=0x55dc8d917b40, limited=0, bytes_in_flight=0, cwnd=26012, state=SlowStart, new_acked=1372
server  | 2.094 DEBUG PMTUD probe of size 1420 succeeded
server  | 2.094 DEBUG PMTUD started with probe size 1470
server  | 2.094 DEBUG PLPMTU changed from 1332 to 1372, updating pacer
server  | 2.094 DEBUG [pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025] Path validated Instant { tv_sec: 521, tv_nsec: 308613248 }
server  | 2.094 DEBUG [Server 87200c3709b8490173f9] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 2.094 DEBUG Building Short dcid Some(CID [8]: f9c10ec87671fd06)
server  | 2.094 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 521, tv_nsec: 308613248 }
server  | 2.094 DEBUG [Server 87200c3709b8490173f9] pn=13 type=Short pri-path:f9c10ec87671fd06 [::]:443->[::ffff:193.167.0.100]:51025 IpTos(Cs0, NotEct) len 35
server  |   TX -> Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: None }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 2.094 DEBUG Setting timeout of 523.1905ms
server  | 2.094 DEBUG Setting timeout of 523.171785ms
client  | 32:42.877 <- (16) Packet A|13|S0|f9c10ec87671fd06|35|2  AckFrame[6-0|?0] ConnectionCloseFrame[0|28|]
server  | 2.618 DEBUG [Server 87200c3709b8490173f9] State change from Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 521, tv_nsec: 832033205 } } -> Closed(Transport(PeerError(0)))
server  | 2.618 INFO Closing timer expired
client  | Terminating Kwik

client exited with code 0
Aborting on container exit...
 Container server  Stopping
 Container client  Stopping
 Container client  Stopped
 Container server  Stopped
 Container sim  Stopping
 Container sim  Stopped

2025-04-30 12:32:54,283 Using the server's key log file.
2025-04-30 12:32:54,292 
2025-04-30 12:32:54,293 Using the server's key log file.
2025-04-30 12:32:54,293 Using the server's key log file.
2025-04-30 12:32:54,301 
2025-04-30 12:32:54,303 Using the server's key log file.
2025-04-30 12:32:54,878 Check of downloaded files succeeded.
2025-04-30 12:32:55,444 Check of Retry succeeded. Token used: 52657472790100f1ea755b95499f494445d9c6e3b015fbefcabb8b4277a1602c53b53e0aaa241e86d16821a87b7091db10713b