2025-12-13 10:33:08,109 Generated random file: polar-titanic-merchant of size: 1024
2025-12-13 10:33:08,109 Requests: https://server4:443/polar-titanic-merchant
2025-12-13 10:33:08,170 
2025-12-13 10:33:08,170 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_0rkwe1or/ TESTCASE_SERVER=v2 TESTCASE_CLIENT=v2 WWW=/tmp/www_2zn5wsee/ DOWNLOADS=/tmp/download_fwsht3ka/ SERVER_LOGS=/tmp/logs_server_skzrr5o4 CLIENT_LOGS=/tmp/logs_client_7ck_4ltg 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/polar-titanic-merchant"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-12-13 10:33:22,104  Container client  Recreate
 Container server  Recreate
 Container client  Recreated
 Container server  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
client  | tx-tcp-ecn-segmentation: off [not requested]
client  | tx-tcp-mangleid-segmentation: off [not requested]
client  | tx-tcp6-segmentation: off [not requested]
client  | tx-udp-segmentation: off [not requested]
client  | tx-checksum-sctp: off
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
server  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + '[' -n v2 ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.SQdw3DCQIK
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.SQdw3DCQIK
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.SQdw3DCQIK -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  |             7e:4a:1c:ca:2d:13:99:d7:7a:ed:73:ae:ff:42:ae:28:
server  |             c2:07:4e:d8
server  |         Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |         Issuer: "O=interop runner Root Certificate Authority"
server  |         Validity:
server  |             Not Before: Sat Dec 13 10:33:08 2025
server  |             Not After : Tue Dec 23 10:33:08 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:58:e0:b1:51:ef:04:fc:15:60:07:3a:dc:61:29:fa:
server  |                     5c:82:40:12:84:cb:cf:af:f3:c2:5d:04:0e:af:58:45:
server  |                     3f:87:c2:46:8b:5f:24:e2:a2:68:36:82:26:a5:1c:05:
server  |                     56:d2:35:0c:2e:b9:84:02:a0:80:e3:8d:8e:0d:1a:c0:
server  |                     84
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  |                 b6:3c:e2:34:93:54:fa:19:1e:f9:b9:7c:03:79:3d:57:
server  |                 05:82:ae:60
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 a4:06:bf:ed:10:76:27:57:c2:6c:29:e8:77:8a:5a:b7:
server  |                 ca:35:bf:80
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:44:02:20:52:7a:e8:36:be:5e:39:01:67:24:13:fc:
server  |         1c:68:33:64:be:28:bf:c4:d3:54:de:b3:a2:a1:12:4b:
server  |         05:20:7f:b0:02:20:1e:05:16:07:d6:6d:84:24:1d:dd:
server  |         81:b7:37:56:59:ed:8c:87:1d:06:d4:68:09:2e:95:99:
server  |         6f:d2:b5:54:91:29
server  |     Fingerprint (SHA-256):
server  |         C7:AC:F9:7E:E3:3F:EC:4E:B9:DF:9B:E4:83:4E:AA:80:EE:50:3D:A2:81:E5:46:B2:E2:AF:74:EC:F0:02:1B:19
server  |     Fingerprint (SHA1):
server  |         5C:D3:10:75:AE:74:06:BA:6C:E0:A2:1A:EE:31:52:30:6A:E4:95:75
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  | + '[' v2 = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test v2 --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.003 DEBUG Default socket send buffer size is Ok(212992)
server  | 0.003 DEBUG Default socket receive buffer size is 1048576, not changing
server  | 0.003 INFO Server waiting for connection on: Ok([::]:443)
client  | Certificate was added to keystore
server  | 0.270 DEBUG [Server] Unsupported version: 57414954
server  | 0.270 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:56661 Tos(Cs0, NotEct) len 23
sim     | server:443 is available after 501.661136ms
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | Capturing on 'eth0'
sim     | Capturing on 'eth1'
sim     | File: /logs/trace_node_left.pcap
sim     | File: /logs/trace_node_right.pcap
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | 33:10.282 Creating connection with server4:443 with v1
client  | 33:10.369 Original destination connection id: 43edac761dd9c290 (scid: 72dc16dd3448cfbd)
client  |           >- CryptoStream[I|ClientHello]
server  | 1.861 DEBUG [Server] Handle initial
server  | 1.861 INFO AddressValidation: no token; accepting
server  | 1.861 INFO [Server] Accept connection CID [8]: 43edac761dd9c290
server  | 1.861 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.863 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.863 INFO [Server ...] Received valid Initial packet with scid CID [8]: 72dc16dd3448cfbd dcid CID [8]: 43edac761dd9c290
server  | 1.863 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=43edac761dd9c290
server  | 1.863 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=30
server  | 1.864 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 1.864 DEBUG [Server 43edac761dd9c290] State change from Init -> WaitInitial
server  | 1.864 DEBUG [Server 43edac761dd9c290] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 1200
server  |   -> RX Crypto { offset: 0, len: 271 }
server  |   -> RX Padding { len: 882 }
server  | 1.864 INFO Compatible upgrade Version1 ==> Version2
server  | 1.864 DEBUG Overwrite initial version Version1 ==> Version2
server  | 1.864 DEBUG 0-RTT: no token, no 0-RTT
client  | 33:10.516 -> Packet I|0|L|1200|2  Token=[] CryptoFrame[0,271] Padding(882)
server  | 1.864 DEBUG Read secret available for Handshake: SymKey [32]: dad4fe24acbba6462f910ea795961d8c7793f7cddcf36f13d6b97d4f4d7ab74b
server  | 1.865 DEBUG Write secret available for Handshake: SymKey [32]: 951dbef5ca4bc50e8cd4c6ba9985bb64beee29b198bf9f9d7cd8cc9e162bb44c
server  | 1.865 DEBUG Writing transport parameters, msg=8
server  | 1.865 DEBUG Read secret available for ApplicationData: SymKey [32]: a5af49058de9a95297f09830bac6d42343a4e538d207e9228b9023ab1d080743
server  | 1.865 DEBUG Write secret available for ApplicationData: SymKey [32]: 02ec36a5e3e8d1e267d5ef0d2c6970802bfd1a7817c4a9cfbeb4161cd52e3efb
server  | 1.865 DEBUG [Agent 0x561f3d42bec0] state -> InProgress
server  | 1.865 DEBUG [CryptoStates] Creating initial cipher state v=Version2, role=Server dcid=43edac761dd9c290
server  | 1.865 DEBUG Making Write Initial CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.865 DEBUG Making Read Initial CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.865 DEBUG [Server 43edac761dd9c290] Compatible upgrade Version1 ==> Version2
server  | 1.865 DEBUG Making Write Handshake CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.865 DEBUG Making Read Handshake CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.865 DEBUG [Crypto] Handshake keys installed
server  | 1.865 DEBUG Making Write ApplicationData CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.865 DEBUG [Crypto] Application write key installed
server  | 1.865 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 840, tv_nsec: 384653087 }
server  | 1.865 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:39459] Make permanent
server  | 1.865 DEBUG [unv-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459] set as primary path
server  | 1.865 DEBUG [Server 43edac761dd9c290] State change from WaitInitial -> Handshaking
server  | 1.865 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.865 DEBUG Building Initial dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.865 DEBUG CRYPTO for in offset=0, len=123
server  | 1.865 DEBUG [Server 43edac761dd9c290] pn=30 type=Initial pri-unv-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 177
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   TX -> Crypto { offset: 0, len: 123 }
server  | 1.865 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.865 DEBUG CRYPTO for hs offset=0, len=726
server  | 1.865 DEBUG [Server 43edac761dd9c290] pn=0 type=Handshake pri-unv-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 951
server  |   TX -> Crypto { offset: 0, len: 726 }
server  | 1.865 DEBUG packet_sent this=0x561f3d49cc40, pn=0, ps=774
server  | 1.865 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.865 DEBUG [Server 43edac761dd9c290] pad Initial from 951 to PLPMTU 1232
server  | 1.865 DEBUG packet_sent this=0x561f3d49cc40, pn=30, ps=458
server  | 1.865 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.865 DEBUG Building Initial dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.865 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.865 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.865 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.865 DEBUG [Server 43edac761dd9c290] delay duration 295.269346ms
server  | 1.865 DEBUG Setting timeout of 295.269346ms
server  | 1.865 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.866 DEBUG Building Initial dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.866 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.866 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.866 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.866 DEBUG [Server 43edac761dd9c290] delay duration 295.232016ms
server  | 1.866 DEBUG Setting timeout of 295.232016ms
client  | 33:10.569 Receiving packet with version v2, while connection version is v1
client  | 33:10.561 <- (1) Packet I|30|L|177|2  Token=[] AckFrame[0|?0] CryptoFrame[0,123]
client  |           -< CryptoStream[I|ServerHello]
client  | 33:10.612 -> Packet I|1|L|1200|2  Token=[] AckFrame[30|?0] Padding(1150)
client  | 33:10.561 <- (1) Packet H|0|L|774|1  CryptoFrame[0,726]
client  | 33:10.617 - unsupported transport parameter 0x2ab2, size 0 (grease-quic-bit)
client  | 33:10.618 - unsupported transport parameter 0xff02de1a, size 2 (delayed-ack)
client  | 33:10.619 Version negotiation resulted in changing version from v1 to v2
server  | 1.950 DEBUG [Server 43edac761dd9c290] pn=1 type=Initial pri-unv-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 1200
server  |   -> RX Ack { largest_acknowledged: 30, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   -> RX Padding { len: 1150 }
server  | 1.950 DEBUG [Server 43edac761dd9c290] Rx ACK space=in, ranges=[30..=30]
server  | 1.950 DEBUG [recovery::Loss] ACK for Initial - largest_acked=30
server  | 1.950 DEBUG on_packets_acked this=0x561f3d49cc40, limited=1, bytes_in_flight=774, cwnd=12320, state=SlowStart, new_acked=458
server  | 1.950 DEBUG Acked crypto frame space=in offset=0 length=123
server  | 1.950 DEBUG [pri-unv-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459] Path validated Instant { tv_sec: 840, tv_nsec: 473404779 }
server  | 1.950 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.950 DEBUG Building Initial dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.950 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.950 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.950 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.950 DEBUG [Server 43edac761dd9c290] delay duration 177.503384ms
server  | 1.950 DEBUG Setting timeout of 177.503384ms
server  | 1.950 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.950 DEBUG Building Initial dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.950 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.950 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.950 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.950 DEBUG [Server 43edac761dd9c290] delay duration 177.347132ms
server  | 1.950 DEBUG Setting timeout of 177.347132ms
client  |           >- CryptoStream[H|Finished]
client  | 33:10.643 -> Packet H|0|L|82|1  CryptoFrame[0,36]
client  |           -< CryptoStream[H|EncryptedExtensions,Certificate,CertificateVerify,Finished]
client  | 33:10.652 -> Packet H|1|L|48|1  AckFrame[0|?0]
server  | 1.979 DEBUG [Server 43edac761dd9c290] Drop packet number space in
server  | 1.979 DEBUG [recovery::Loss] Reset loss recovery state for Initial
server  | 1.980 DEBUG [Server 43edac761dd9c290] pn=0 type=Handshake pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 82
server  |   -> RX Crypto { offset: 0, len: 36 }
server  | 1.980 DEBUG [Agent 0x561f3d42bec0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 23, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
server  | 1.980 DEBUG [Server 43edac761dd9c290] TLS connection complete
server  | 1.980 DEBUG [pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459] Path validated Instant { tv_sec: 840, tv_nsec: 503290521 }
server  | 1.980 DEBUG Making Read ApplicationData CryptoDxState, v=Version2 cipher=4865 min_pn=0
server  | 1.980 DEBUG [Crypto] application read keys installed
server  | 1.980 DEBUG [Server 43edac761dd9c290] State change from Handshaking -> Connected
server  | 1.980 DEBUG [Server 43edac761dd9c290] State change from Connected -> Confirmed
server  | 1.980 DEBUG PMTUD started, PLPMTU is now 1280
server  | 1.980 DEBUG PMTUD started with probe size 1380
server  | 1.980 INFO [Server 43edac761dd9c290] Connection established
server  | 1.980 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 840, tv_nsec: 503290521 }
server  | 1.980 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.980 DEBUG Building Handshake dcid Some(CID [8]: 72dc16dd3448cfbd) scid Some(CID [10]: 28cd7526d883d3459333)
server  | 1.980 DEBUG [Server 43edac761dd9c290] pn=1 type=Handshake pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 49
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.980 DEBUG [Server 43edac761dd9c290] Drop packet number space hs
server  | 1.980 DEBUG [recovery::Loss] Reset loss recovery state for Handshake
server  | 1.980 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.980 DEBUG [Server 43edac761dd9c290] pn=0 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [150, 238, 201, 189, 111, 203, 132, 172, 135, 140], stateless_reset_token: Token([127, 134, 15, 22, 102, 201, 202, 52, 77, 17, 123, 200, 65, 30, 25, 142]) }
server  |   TX -> Padding { len: 1226 }
server  | 1.980 DEBUG packet_sent this=0x561f3d49cc40, pn=0, ps=1283
server  | 1.980 DEBUG ECN probing: sent 1 probes
server  | 1.980 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.980 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.980 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.980 DEBUG [Server 43edac761dd9c290] pn=1 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1305 }
server  | 1.980 DEBUG packet_sent this=0x561f3d49cc40, pn=1, ps=1332
server  | 1.980 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.980 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.980 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.980 DEBUG ECN probing: sent 2 probes
server  | 1.980 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.981 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.981 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.981 DEBUG [Server 43edac761dd9c290] delay duration 3.861582ms
server  | 1.981 DEBUG Setting timeout of 3.861582ms
server  | 1.982 DEBUG [Server 43edac761dd9c290] send session ticket 406a000843edac761dd9c2900104800075300404802000000504801000000604801000000704801000000801100901100b01140e01080f0a28cd7526d883d345933311146b3343cf7aba6aca6b3343cf00000001ff00001d6ab200c0000000ff02de1a0243e820048000ffff686921
server  | 1.982 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.982 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.982 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.982 DEBUG [Server 43edac761dd9c290] delay duration 2.590193ms
server  | 1.982 DEBUG Setting timeout of 2.590193ms
server  | 1.986 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.986 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.986 DEBUG CRYPTO for ap offset=0, len=321
server  | 1.986 DEBUG [Server 43edac761dd9c290] pn=2 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 396
server  |   TX -> Crypto { offset: 0, len: 321 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 82, 187, 117, 219, 10, 181, 59, 246, 251, 74, 35, 96, 21, 164, 255, 96, 71, 107, 155, 228, 232, 9, 186, 16, 233, 109, 96, 119, 176, 57, 55, 144, 5, 195, 201, 39] }
server  | 1.986 DEBUG packet_sent this=0x561f3d49cc40, pn=2, ps=396
server  | 1.986 DEBUG ECN probing: sent 3 probes
server  | 1.986 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.986 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.987 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.987 DEBUG [Server 43edac761dd9c290] delay duration 291.000319ms
server  | 1.987 DEBUG Setting timeout of 291.000319ms
server  | 1.987 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.987 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.987 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.987 DEBUG [Server 43edac761dd9c290] delay duration 290.920831ms
server  | 1.987 DEBUG Setting timeout of 290.920831ms
server  | 1.988 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 1
server  | 1.988 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.988 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.988 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.988 DEBUG [Server 43edac761dd9c290] delay duration 289.257579ms
server  | 1.988 DEBUG Setting timeout of 289.257579ms
server  | 1.988 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.988 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.988 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.988 DEBUG [Server 43edac761dd9c290] delay duration 289.217023ms
server  | 1.988 DEBUG Setting timeout of 289.217023ms
client  | 33:10.658 -> Packet A|0|S0|28cd7526d883d3459333|61|1  StreamFrame[0(CIB),0,29,fin]
server  | 1.995 DEBUG [Server 43edac761dd9c290] pn=0 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 61
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 29, fin: true }
server  | 1.995 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 840, tv_nsec: 538597068 }
server  | 1.995 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.995 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.995 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.995 DEBUG [Server 43edac761dd9c290] delay duration 20ms
server  | 1.995 DEBUG Setting timeout of 20ms
server  | 1.995 DEBUG Path = 'polar-titanic-merchant'
server  | 1.995 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.995 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.995 DEBUG [Server 43edac761dd9c290] pn=3 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 1054
server  |   TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true }
server  | 1.995 DEBUG packet_sent this=0x561f3d49cc40, pn=3, ps=1054
server  | 1.995 DEBUG ECN probing: sent 4 probes
server  | 1.995 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.995 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 1.995 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.995 DEBUG [Server 43edac761dd9c290] delay duration 19.685622ms
server  | 1.995 DEBUG Setting timeout of 19.685622ms
client  | 33:10.675 <- (2) Packet H|1|L|49|1  AckFrame[0|?0]
client  | 33:10.675 <- (2) Packet A|0|S0|72dc16dd3448cfbd|1283|3  HandshakeDoneFrame[] NewConnectionIdFrame[1,<0|96eec9bd6fcb84ac878c|7f860f1666c9ca344d117bc8411e198e] Padding(1226)
client  | 33:10.676 <- (3) Packet A|1|S0|72dc16dd3448cfbd|1332|2  PingFrame[] Padding(1305)
client  | 33:10.685 -> Packet A|1|S0|28cd7526d883d3459333|34|1  AckFrame[1-0|?1]
client  | 33:10.683 <- (4) Packet A|2|S0|72dc16dd3448cfbd|396|2  CryptoFrame[0,321] NewTokenFrame[ad9a8b8d86010052bb75db0ab53bf6fb4a236015a4ff60476b9be4e809ba10e96d6077b039379005c3c927]
client  |           -< CryptoStream[A|NewSessionTicket]
client  | 33:10.690 <- (5) Packet A|3|S0|72dc16dd3448cfbd|1054|1  StreamFrame[0(CIB),0,1024,fin]
client  | 33:10.693 -> Packet A|2|S0|28cd7526d883d3459333|34|1  AckFrame[3-0|?1]
client  | Get requested finished in 0.33 sec (0.00 MB/s).
server  | 2.016 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.016 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.016 DEBUG [Server 43edac761dd9c290] pn=4 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 32
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 2700, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 2.016 DEBUG ECN probing: sent 5 probes
server  | 2.017 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.017 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.017 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.017 DEBUG [Server 43edac761dd9c290] delay duration 269.475927ms
server  | 2.017 DEBUG Setting timeout of 269.475927ms
server  | 2.017 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.017 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.017 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 2.017 DEBUG [Server 43edac761dd9c290] delay duration 269.399524ms
server  | 2.017 DEBUG Setting timeout of 269.399524ms
client  | 33:10.699 Closing ClientConnection[43edac761dd9c290/72dc16dd3448cfbd(V2) with server4/193.167.100.100:443] (reason: ImmediateClose)
server  | 2.024 DEBUG [Server 43edac761dd9c290] pn=1 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 125, first_ack_range: 1, ack_ranges: [], ecn_count: None }
server  | 2.024 DEBUG [Server 43edac761dd9c290] Rx ACK space=ap, ranges=[0..=1]
server  | 2.024 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1
server  | 2.024 DEBUG on_packets_acked this=0x561f3d49cc40, limited=1, bytes_in_flight=1450, cwnd=12320, state=SlowStart, new_acked=2615
server  | 2.024 DEBUG PMTUD probe of size 1380 succeeded
server  | 2.024 DEBUG PMTUD started with probe size 1420
server  | 2.024 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 2.024 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.025 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 2.025 DEBUG [Server 43edac761dd9c290] pn=5 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1345 }
server  | 2.025 DEBUG packet_sent this=0x561f3d49cc40, pn=5, ps=1372
server  | 2.025 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.025 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG ECN probing: sent 6 probes
server  | 2.025 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.025 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG [Server 43edac761dd9c290] delay duration 285.47996ms
server  | 2.025 DEBUG Setting timeout of 285.47996ms
server  | 2.025 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.025 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.025 DEBUG [Server 43edac761dd9c290] delay duration 285.449763ms
server  | 2.025 DEBUG Setting timeout of 285.449763ms
client  | 33:10.702 -> Packet A|3|S0|28cd7526d883d3459333|32|1  ConnectionCloseFrame[0|0|]
server  | 2.029 DEBUG [Server 43edac761dd9c290] pn=2 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 34
server  |   -> RX Ack { largest_acknowledged: 3, ack_delay: 125, first_ack_range: 3, ack_ranges: [], ecn_count: None }
server  | 2.029 DEBUG [Server 43edac761dd9c290] Rx ACK space=ap, ranges=[0..=3]
server  | 2.029 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=3
server  | 2.029 DEBUG on_packets_acked this=0x561f3d49cc40, limited=1, bytes_in_flight=1372, cwnd=12320, state=SlowStart, new_acked=1450
server  | 2.029 DEBUG Acked crypto frame space=ap offset=0 length=321
server  | 2.029 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.029 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.029 DEBUG [Server 43edac761dd9c290] pn=6 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 28
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 2.029 DEBUG packet_sent this=0x561f3d49cc40, pn=6, ps=29
server  | 2.029 DEBUG ECN probing: sent 7 probes
server  | 2.030 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.030 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.030 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.030 DEBUG [Server 43edac761dd9c290] delay duration 283.497171ms
server  | 2.030 DEBUG Setting timeout of 283.497171ms
server  | 2.030 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.030 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.030 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.030 DEBUG [Server 43edac761dd9c290] delay duration 283.313297ms
server  | 2.030 DEBUG Setting timeout of 283.313297ms
client  | 33:10.711 <- (6) Packet A|4|S0|72dc16dd3448cfbd|32|1  AckFrame[0|?21]
client  | 33:10.712 -> Packet A|4|S0|28cd7526d883d3459333|32|1  ConnectionCloseFrame[0|0|]
server  | 2.039 DEBUG [Server 43edac761dd9c290] pn=3 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, NotEct) len 32
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  | 2.039 INFO [Server 43edac761dd9c290] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 2.039 DEBUG [Server 43edac761dd9c290] State change from Confirmed -> Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 841, tv_nsec: 415141295 } }
server  | 2.039 DEBUG [pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459] Path validated Instant { tv_sec: 840, tv_nsec: 562745868 }
server  | 2.039 DEBUG [Server 43edac761dd9c290] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 2.039 DEBUG Building Short dcid Some(CID [8]: 72dc16dd3448cfbd)
server  | 2.039 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 840, tv_nsec: 562745868 }
server  | 2.039 DEBUG [Server 43edac761dd9c290] pn=7 type=Short pri-path:72dc16dd3448cfbd [::]:443->[::ffff:193.167.0.100]:39459 Tos(Cs0, Ect0) len 35
server  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 3, ack_ranges: [], ecn_count: None }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 2.039 DEBUG ECN probing: sent 8 probes
server  | 2.039 DEBUG Setting timeout of 852.297724ms
server  | 2.039 DEBUG Setting timeout of 852.288937ms
client  | 33:10.720 <- (7) Packet A|5|S0|72dc16dd3448cfbd|1372|2  PingFrame[] Padding(1345)
client  | 33:10.721 -> Packet A|5|S0|28cd7526d883d3459333|32|1  ConnectionCloseFrame[0|0|]
client  | 33:10.724 <- (8) Packet A|6|S0|72dc16dd3448cfbd|29|2  MaxStreamsFrame[B,17] Padding(1)
server  | 2.049 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 841, tv_nsec: 415141295 } }; Total: 2
server  | 2.049 DEBUG Setting timeout of 842.635508ms
server  | 2.049 DEBUG Setting timeout of 842.614649ms
client  | 33:10.733 <- (9) Packet A|7|S0|72dc16dd3448cfbd|35|2  AckFrame[3-0|?0] ConnectionCloseFrame[0|28|]
server  | 2.057 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 841, tv_nsec: 415141295 } }; Total: 3
server  | 2.057 DEBUG Setting timeout of 833.742109ms
server  | 2.057 DEBUG Setting timeout of 833.72117ms
server  | 2.891 DEBUG [Server 43edac761dd9c290] State change from Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 841, tv_nsec: 415141295 } } -> Closed(Transport(Peer(0)))
server  | 2.892 INFO Closing timer expired
client  | Terminating Kwik

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-12-13 10:33:22,201 Using the client's key log file.
2025-12-13 10:33:22,213 
2025-12-13 10:33:22,214 Using the client's key log file.
2025-12-13 10:33:22,214 Using the client's key log file.
2025-12-13 10:33:22,226 
2025-12-13 10:33:22,227 Using the client's key log file.
2025-12-13 10:33:23,199 Check of downloaded files succeeded.