2025-04-30 08:45:10,221 Generated random file: rdqrnqaunc of size: 1024
2025-04-30 08:45:10,221 Requests: https://server4:443/rdqrnqaunc
2025-04-30 08:45:10,281 
2025-04-30 08:45:10,282 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_vp8tp36z/ TESTCASE_SERVER=ecn TESTCASE_CLIENT=ecn WWW=/tmp/www_rk2ry0i4/ DOWNLOADS=/tmp/download_vvpszsag/ SERVER_LOGS=/tmp/logs_server_dgqb7yqe CLIENT_LOGS=/tmp/logs_client_8osoxnuw SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/aws/s2n-quic/s2n-quic-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/rdqrnqaunc"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 08:45:22,713  Container sim  Created
 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
client  | x86_64
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  | wait-for-it.sh: waiting 30 seconds for sim:57832
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 ecn ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.u6XpJW2m71
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.u6XpJW2m71
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.u6XpJW2m71 -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  |             13:64:c8:61:90:df:d4:4e:33:73:b8:04:0a:77:98:4d:
server  |             5e:20:9c:36
server  |         Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |         Issuer: "O=interop runner Root Certificate Authority"
server  |         Validity:
server  |             Not Before: Wed Apr 30 08:45:10 2025
server  |             Not After : Sat May 10 08:45:10 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:2e:a1:f8:6d:fa:a0:cc:28:97:61:50:81:ee:55:96:
server  |                     b0:75:78:1f:6d:8a:c4:48:0a:46:f2:4b:00:a5:f0:52:
server  |                     b3:89:93:7c:47:be:a1:ce:43:b5:4c:1e:81:c1:9a:02:
server  |                     28:d9:43:36:f3:fd:18:9b:e4:eb:ab:c5:ab:5f:21:bc:
server  |                     b8
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  |                 74:d7:d1:35:08:ae:30:1f:03:99:d9:b7:75:68:ce:88:
server  |                 26:a4:0f:0d
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 6e:b1:7a:a7:e5:bf:08:1e:95:18:68:d3:61:9a:48:ea:
server  |                 0b:ad:97:02
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:44:02:20:13:cc:af:48:2b:da:74:ef:07:26:be:0a:
server  |         f8:03:01:50:79:2c:10:d6:39:b5:88:fa:db:29:f7:46:
server  |         35:d4:95:2d:02:20:1b:52:42:79:f9:55:38:40:67:5b:
server  |         52:fc:8d:4f:86:ac:17:2d:ab:4e:c7:0d:30:fa:51:b1:
server  |         7c:fe:0b:aa:96:33
server  |     Fingerprint (SHA-256):
server  |         53:C4:B4:3D:5B:74:39:60:ED:65:55:96:E5:55:BD:51:0B:EB:9E:1A:29:67:34:1D:7F:4A:EA:C3:89:F3:DE:C2
server  |     Fingerprint (SHA1):
server  |         69:2E:92:51:D9:0B:45:3B:5E:2D:A2:0C:4E:7B:AC:30:0B:EC:A0:30
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  | + '[' ecn = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test ecn --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]:59877 IpTos(Cs0, NotEct) len 15
server  | 0.798 DEBUG [Server] Unsupported version: 57414954
server  | 0.798 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59877 IpTos(Cs0, NotEct) len 15
server  | 0.798 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.798 DEBUG [Server] Unsupported version: 57414954
server  | 0.798 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59877 IpTos(Cs0, NotEct) len 15
server  | 0.798 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | server:443 is available after 1.061204819s
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | connecting to server4 at 193.167.100.100:443
server  | 1.028 DEBUG [Server] Handle initial
server  | 1.028 INFO AddressValidation: no token; accepting
server  | 1.028 INFO [Server] Accept connection CID [8]: 0808e53e998c2af0
server  | 1.028 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.030 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.030 INFO [Server ...] Received valid Initial packet with scid CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07 dcid CID [8]: 0808e53e998c2af0
server  | 1.030 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=0808e53e998c2af0
server  | 1.030 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.030 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.030 DEBUG [Server 0808e53e998c2af0] State change from Init -> WaitInitial
server  | 1.030 DEBUG [Server 0808e53e998c2af0] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 1200
server  |   -> RX Crypto { offset: 0, len: 287 }
server  |   -> RX Padding { len: 858 }
server  | 1.030 DEBUG Read Ok(287) bytes
server  | 1.030 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.031 DEBUG Read secret available for Handshake: SymKey [32]: 8549fd3702c86255816f366722a44260b9d3303efae3f669e82a4a5bf06e3db7
server  | 1.031 DEBUG Write secret available for Handshake: SymKey [32]: 7b302a69a1237fe20a96547d40f061fdb9304cdde01d1941853f47a30c46abf8
server  | 1.031 DEBUG Writing transport parameters, msg=8
server  | 1.031 DEBUG Read secret available for ApplicationData: SymKey [32]: 666b402f1c9863e2408b002366330fa5f1cad166215dbacaea1528577fdfbc9e
server  | 1.031 DEBUG Write secret available for ApplicationData: SymKey [32]: 60e2c7c9b5743c65b2afbdeeba381c867d5d44427b80fc8027bfe13d3dc36fdd
server  | 1.032 DEBUG [Agent 0x56271fc341d0] state -> InProgress
server  | 1.032 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.032 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.032 DEBUG [Crypto] Handshake keys installed
server  | 1.032 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.032 DEBUG [Crypto] Application write key installed
server  | 1.032 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 375, tv_nsec: 104484390 }
server  | 1.032 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:50906] Make permanent
server  | 1.032 DEBUG [unv-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906] set as primary path
server  | 1.032 DEBUG [Server 0808e53e998c2af0] State change from WaitInitial -> Handshaking
server  | 1.032 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG CRYPTO for in offset=0, len=123
server  | 1.032 DEBUG [Server 0808e53e998c2af0] pn=0 type=Initial pri-unv-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 188
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  |   TX -> Crypto { offset: 0, len: 123 }
server  | 1.032 DEBUG Building Handshake dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG CRYPTO for hs offset=0, len=723
server  | 1.032 DEBUG [Server 0808e53e998c2af0] pn=0 type=Handshake pri-unv-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 967
server  |   TX -> Crypto { offset: 0, len: 723 }
server  | 1.032 DEBUG packet_sent this=0x56271fc33b40, pn=0, ps=779
server  | 1.032 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.032 DEBUG [Server 0808e53e998c2af0] pad Initial from 967 to PLPMTU 1232
server  | 1.032 DEBUG packet_sent this=0x56271fc33b40, pn=0, ps=453
server  | 1.032 DEBUG ECN probing: sent 1 probes
server  | 1.032 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG Building Handshake dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG [Server 0808e53e998c2af0] delay duration 296.590497ms
server  | 1.032 DEBUG Setting timeout of 296.590497ms
server  | 1.032 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG Building Handshake dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.032 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG [Server 0808e53e998c2af0] delay duration 296.547386ms
server  | 1.032 DEBUG Setting timeout of 296.547386ms
client  | GET /rdqrnqaunc
server  | 1.067 DEBUG [Server 0808e53e998c2af0] pn=1 type=Initial pri-unv-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 72
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 1985, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  |   -> RX Padding { len: 10 }
server  | 1.067 DEBUG [Server 0808e53e998c2af0] Rx ACK space=in, ranges=[0..=0]
server  | 1.068 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.068 DEBUG on_packets_acked this=0x56271fc33b40, limited=1, bytes_in_flight=779, cwnd=12320, state=SlowStart, new_acked=453
server  | 1.068 DEBUG Acked crypto frame space=in offset=0 length=123
server  | 1.068 DEBUG [pri-unv-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906] Path validated Instant { tv_sec: 375, tv_nsec: 143516880 }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] Drop packet number space in
server  | 1.068 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.068 DEBUG [Server 0808e53e998c2af0] pn=0 type=Handshake pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 1128
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 1985, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  |   -> RX Crypto { offset: 0, len: 36 }
server  |   -> RX Padding { len: 1028 }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] Rx ACK space=hs, ranges=[0..=0]
server  | 1.068 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.068 DEBUG on_packets_acked this=0x56271fc33b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=779
server  | 1.068 DEBUG Acked crypto frame space=hs offset=0 length=723
server  | 1.068 DEBUG Read Ok(36) bytes
server  | 1.068 DEBUG [Agent 0x56271fc341d0] 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.068 DEBUG [Server 0808e53e998c2af0] TLS connection complete
server  | 1.068 DEBUG [pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906] Path validated Instant { tv_sec: 375, tv_nsec: 143516880 }
server  | 1.068 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.068 DEBUG [Crypto] application read keys installed
server  | 1.068 DEBUG [Server 0808e53e998c2af0] State change from Handshaking -> Connected
server  | 1.068 DEBUG [Server 0808e53e998c2af0] State change from Connected -> Confirmed
server  | 1.068 DEBUG PMTUD started with probe size 1380
server  | 1.068 INFO [Server 0808e53e998c2af0] Connection established
server  | 1.068 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 375, tv_nsec: 143516880 }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.068 DEBUG Building Handshake dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07) scid Some(CID [10]: 6d3d5d04abb56629fa18)
server  | 1.068 DEBUG [Server 0808e53e998c2af0] pn=1 type=Handshake pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 60
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] Drop packet number space hs
server  | 1.068 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.068 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.068 DEBUG [Server 0808e53e998c2af0] pn=0 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [7, 224, 138, 25, 211, 57, 174, 206, 187, 38], stateless_reset_token: [18, 106, 35, 105, 3, 204, 165, 36, 248, 221, 53, 18, 166, 61, 188, 114] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [164, 232, 74, 51, 47, 12, 190, 171, 46, 35], stateless_reset_token: [35, 37, 154, 177, 119, 180, 62, 191, 0, 126, 134, 201, 80, 239, 154, 89] }
server  |   TX -> Padding { len: 1177 }
server  | 1.068 DEBUG packet_sent this=0x56271fc33b40, pn=0, ps=1272
server  | 1.068 DEBUG ECN probing: sent 2 probes
server  | 1.068 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.068 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.068 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.068 DEBUG [Server 0808e53e998c2af0] pn=1 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1297 }
server  | 1.068 DEBUG packet_sent this=0x56271fc33b40, pn=1, ps=1332
server  | 1.068 DEBUG ECN probing: sent 3 probes
server  | 1.068 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] delay duration 1.526044ms
server  | 1.068 DEBUG Setting timeout of 1.526044ms
server  | 1.068 DEBUG [Server 0808e53e998c2af0] pn=0 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 51
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 0, fin: false }
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  | 1.068 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 375, tv_nsec: 164189687 }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG [Server 0808e53e998c2af0] delay duration 1.501148ms
server  | 1.068 DEBUG Setting timeout of 1.501148ms
server  | 1.069 DEBUG [Server 0808e53e998c2af0] send session ticket 406300080808e53e998c2af00104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a6d3d5d04abb56629fa18110c00000001aaeaaa2a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.069 DEBUG Path = 'rdqrnqaunc'
server  | 1.069 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.069 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG [Server 0808e53e998c2af0] delay duration 438.251µs
server  | 1.069 DEBUG Setting timeout of 438.251µs
server  | 1.071 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.071 DEBUG CRYPTO for ap offset=0, len=166
server  | 1.071 DEBUG [Server 0808e53e998c2af0] pn=2 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true }
server  |   TX -> Crypto { offset: 0, len: 166 }
server  | 1.071 DEBUG packet_sent this=0x56271fc33b40, pn=2, ps=1232
server  | 1.071 DEBUG ECN probing: sent 4 probes
server  | 1.071 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.071 DEBUG CRYPTO for ap offset=166, len=139
server  | 1.071 DEBUG [Server 0808e53e998c2af0] pn=3 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 223
server  |   TX -> Crypto { offset: 166, len: 139 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 111, 203, 18, 40, 87, 113, 219, 115, 119, 155, 133, 18, 121, 83, 155, 230, 148, 74, 135, 78, 113, 32, 249, 241, 69, 73, 142, 139, 209, 9, 105, 90, 158, 44, 18, 206] }
server  | 1.071 DEBUG packet_sent this=0x56271fc33b40, pn=3, ps=223
server  | 1.071 DEBUG ECN probing: sent 5 probes
server  | 1.071 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG [Server 0808e53e998c2af0] delay duration 16.636857ms
server  | 1.071 DEBUG Setting timeout of 16.636857ms
server  | 1.071 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG [Server 0808e53e998c2af0] delay duration 16.617731ms
server  | 1.072 DEBUG Setting timeout of 16.617731ms
client  | Request /rdqrnqaunc completed successfully
server  | 1.089 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.089 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.089 DEBUG [Server 0808e53e998c2af0] pn=4 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 43
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 2569, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  | 1.089 DEBUG ECN probing: sent 6 probes
server  | 1.089 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.089 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.089 DEBUG [Server 0808e53e998c2af0] delay duration 105.152316ms
server  | 1.089 DEBUG Setting timeout of 105.152316ms
server  | 1.089 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.089 DEBUG Building Short dcid Some(CID [16]: 49c4079ed0bdc1f3cf88902c342d7e07)
server  | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.089 DEBUG [Server 0808e53e998c2af0] delay duration 105.125345ms
server  | 1.089 DEBUG Setting timeout of 105.125345ms
server  | 1.102 DEBUG [Server 0808e53e998c2af0] pn=1 type=Short pri-path:49c4079ed0bdc1f3cf88902c342d7e07 [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 147
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 100, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 1, connection_id: [234, 86, 79, 28, 181, 46, 204, 73, 56, 254, 48, 249, 133, 220, 192, 222], stateless_reset_token: [3, 132, 180, 97, 160, 237, 187, 128, 184, 245, 168, 183, 73, 136, 84, 80] }
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 1, connection_id: [130, 239, 178, 150, 161, 104, 149, 135, 201, 164, 223, 186, 101, 6, 4, 181], stateless_reset_token: [7, 241, 214, 145, 46, 40, 131, 106, 146, 93, 37, 46, 75, 55, 153, 30] }
server  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 1, connection_id: [75, 83, 216, 237, 107, 17, 137, 72, 172, 154, 67, 112, 120, 223, 130, 251], stateless_reset_token: [19, 247, 38, 44, 198, 30, 226, 116, 27, 140, 166, 162, 164, 165, 70, 113] }
server  |   -> RX RetireConnectionId { sequence_number: 0 }
server  | 1.102 DEBUG [Server 0808e53e998c2af0] Rx ACK space=ap, ranges=[0..=0]
server  | 1.102 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
server  | 1.102 DEBUG on_packets_acked this=0x56271fc33b40, limited=1, bytes_in_flight=2787, cwnd=12320, state=SlowStart, new_acked=1272
server  | 1.102 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 375, tv_nsec: 197760500 }
server  | 1.102 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG Building Short dcid Some(CID [16]: ea564f1cb52ecc4938fe30f985dcc0de)
server  | 1.102 DEBUG [Server 0808e53e998c2af0] pn=5 type=Short pri-path:ea564f1cb52ecc4938fe30f985dcc0de [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 66
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [248, 89, 68, 95, 71, 230, 137, 132, 88, 232], stateless_reset_token: [199, 23, 136, 155, 26, 55, 225, 137, 243, 120, 155, 110, 18, 185, 186, 169] }
server  |   TX -> RetireConnectionId { sequence_number: 0 }
server  | 1.102 DEBUG packet_sent this=0x56271fc33b40, pn=5, ps=66
server  | 1.102 DEBUG ECN probing: sent 7 probes
server  | 1.102 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG Building Short dcid Some(CID [16]: ea564f1cb52ecc4938fe30f985dcc0de)
server  | 1.102 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG [Server 0808e53e998c2af0] delay duration 19.724685ms
server  | 1.102 DEBUG Setting timeout of 19.724685ms
server  | 1.102 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG Building Short dcid Some(CID [16]: ea564f1cb52ecc4938fe30f985dcc0de)
server  | 1.102 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG [Server 0808e53e998c2af0] delay duration 19.689931ms
server  | 1.102 DEBUG Setting timeout of 19.689931ms
server  | 1.120 DEBUG [Server 0808e53e998c2af0] pn=2 type=Short pri-path:ea564f1cb52ecc4938fe30f985dcc0de [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 47
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  |   -> RX Padding { len: 15 }
server  | 1.120 INFO [Server 0808e53e998c2af0] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.120 DEBUG [Server 0808e53e998c2af0] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 375, tv_nsec: 532875555 } }
server  | 1.120 DEBUG [Server 0808e53e998c2af0] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.120 DEBUG Building Short dcid Some(CID [16]: ea564f1cb52ecc4938fe30f985dcc0de)
server  | 1.120 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 375, tv_nsec: 196472664 }
server  | 1.120 DEBUG [Server 0808e53e998c2af0] pn=6 type=Short pri-path:ea564f1cb52ecc4938fe30f985dcc0de [::]:443->[::ffff:193.167.0.100]:50906 IpTos(Cs0, Ect0) len 46
server  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 1.121 DEBUG ECN probing: sent 8 probes
server  | 1.121 DEBUG Setting timeout of 336.235168ms
server  | 1.121 DEBUG Setting timeout of 336.219518ms
server  | 1.186 WARN [Server ...] Dropped received packet: State Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 375, tv_nsec: 532875555 } }; Total: 1
server  | 1.186 DEBUG Setting timeout of 270.602476ms
server  | 1.186 DEBUG Setting timeout of 270.56737ms
server  | 1.458 DEBUG [Server 0808e53e998c2af0] State change from Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 375, tv_nsec: 532875555 } } -> Closed(Transport(PeerError(0)))
server  | 1.458 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 08:45:22,814 Using the client's key log file.
2025-04-30 08:45:22,823 
2025-04-30 08:45:22,824 Using the client's key log file.
2025-04-30 08:45:22,824 Using the client's key log file.
2025-04-30 08:45:22,832 
2025-04-30 08:45:22,833 Using the client's key log file.
2025-04-30 08:45:23,123 Check of downloaded files succeeded.
2025-04-30 08:45:23,703 Using the client's key log file.
2025-04-30 08:45:23,991 Check of downloaded files succeeded.
2025-04-30 08:45:24,846 ECN.NONE 1
2025-04-30 08:45:24,846 ECN.ECT1 0
2025-04-30 08:45:24,846 ECN.ECT0 5
2025-04-30 08:45:24,846 ECN.CE 0
2025-04-30 08:45:25,139 ECN.NONE 0
2025-04-30 08:45:25,139 ECN.ECT1 0
2025-04-30 08:45:25,139 ECN.ECT0 8
2025-04-30 08:45:25,139 ECN.CE 0