2025-04-30 09:37:45,586 Generated random file: pprafbdtug of size: 10240
2025-04-30 09:37:45,586 Requests: https://server4:443/pprafbdtug
2025-04-30 09:37:45,646 
2025-04-30 09:37:45,646 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_zw98fq52/ TESTCASE_SERVER=retry TESTCASE_CLIENT=retry WWW=/tmp/www_tlm78sdc/ DOWNLOADS=/tmp/download_ob0sjfce/ SERVER_LOGS=/tmp/logs_server_agi6i5k3 CLIENT_LOGS=/tmp/logs_client_z1x2hkq5 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=martenseemann/quic-go-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/pprafbdtug"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 09:37:57,663  Container sim  Created
 Container server  Recreate
 Container client  Recreate
 Container client  Recreated
 Container server  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
server  | Setting up routes...
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]
server  | Actual changes:
client  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-checksum-ip-generic: off
client  | tx-tcp6-segmentation: off [not requested]
server  | tx-tcp-segmentation: off [not requested]
client  | tx-udp-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
client  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::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
client  | Using commit: e4bb2dbd5557c9417b30cf9fcd9032fd6fea5366
server  | + P12CERT=/tmp/tmp.mN2dfzIguv
server  | + mkdir -p /neqo/db
server  | + certutil -N -d sql:/neqo/db --empty-password
client  | wait-for-it.sh: waiting 10 seconds for sim:57832
server  | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.mN2dfzIguv
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.mN2dfzIguv -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  |             76:fc:f8:a0:0d:4f:03:0e:79:76:49:54:45:49:87:94:
server  |             98:0a:63:9f
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 09:37:45 2025
server  |             Not After : Sat May 10 09:37:45 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:b4:ee:e7:f6:5e:bd:89:a3:7c:05:e6:82:59:03:f3:
server  |                     e3:95:ed:10:5f:f5:cc:ef:76:38:f8:8d:46:8e:53:b5:
server  |                     f7:25:4f:af:af:ec:40:d0:cc:2c:fc:77:07:32:08:21:
server  |                     ee:0d:f8:b7:59:c2:8a:1e:be:15:5e:9f:2f:32:c5:a4:
server  |                     7e
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  |                 be:c6:82:6e:0f:d7:79:d9:97:52:5d:98:e1:fd:63:fb:
server  |                 e2:2a:9d:e2
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 4d:59:ba:c7:17:6f:43:06:a8:42:94:ca:94:bc:84:09:
server  |                 a5:67:f0:7b
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:46:02:21:00:a4:b2:12:0a:fb:2c:77:97:b1:8a:be:
server  |         07:71:e3:62:2c:da:a2:4c:74:04:e2:a8:46:d8:c4:ad:
server  |         bd:c6:5d:2c:18:02:21:00:ca:10:af:da:9e:64:58:9a:
server  |         0a:39:13:aa:bd:9f:d8:4b:d9:68:d2:fb:d0:e1:f2:45:
server  |         b4:3d:51:c8:0a:d9:3f:47
server  |     Fingerprint (SHA-256):
server  |         56:DD:A4:39:A4:66:41:66:6C:37:25:28:F9:96:5E:9B:DB:2B:12:3E:84:24:39:42:AF:FC:A8:09:90:BE:93:70
server  |     Fingerprint (SHA1):
server  |         BC:1A:CA:3A:87:E7:54:49:D8:0A:0E:09:CA:E8:26:1A:43:D3:F4:63
server  | 
server  |     Mozilla-CA-Policy: false (attribute missing)
server  |     Certificate Trust Flags:
server  |         SSL Flags:
server  |             User
server  |         Email Flags:
server  |             User
server  |         Object Signing Flags:
server  |             User
server  | 
server  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT")
server  | + '[' retry = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test retry --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443'
server  | ++ tee -i -a /logs/server.log
server  | 0.000 DEBUG Logging initialized
server  | 0.002 DEBUG Default socket send buffer size is 212992
server  | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing
server  | 0.002 INFO Server waiting for connection on: [::]:443
server  | 0.765 DEBUG [Server] Unsupported version: 57414954
server  | 0.765 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52293 IpTos(Cs0, NotEct) len 15
server  | 0.765 DEBUG [Server] Unsupported version: 57414954
server  | 0.765 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52293 IpTos(Cs0, NotEct) len 15
server  | 0.765 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.765 DEBUG [Server] Unsupported version: 57414954
server  | 0.765 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52293 IpTos(Cs0, NotEct) len 15
server  | 0.765 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | server:443 is available after 1.018437069s
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  | Starting QUIC client...
client  | Client params: 
client  | Test case: retry
server  | 0.997 DEBUG [Server] Handle initial
server  | 0.997 INFO AddressValidation: no token; validating
server  | 0.997 INFO [Server] Send retry for CID [19]: a250d0fd226d79818fe31709a36be8c0d11a8e
server  | 0.997 DEBUG [Server] type=Retry path:a250d0fd226d79818fe31709a36be8c0d11a8e [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 95
server  | 1.029 DEBUG [Server] Handle initial
server  | 1.029 INFO AddressValidation: valid Retry token for a250d0fd226d79818fe31709a36be8c0d11a8e
server  | 1.029 INFO [Server] Accept connection CID [19]: a250d0fd226d79818fe31709a36be8c0d11a8e
server  | 1.029 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.031 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.031 INFO [Server ...] Received valid Initial packet with scid CID [0]:  dcid CID [10]: 798a9538243b45b09052
server  | 1.031 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=798a9538243b45b09052
server  | 1.031 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.031 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.031 DEBUG [Server 798a9538243b45b09052] State change from Init -> WaitInitial
server  | 1.031 DEBUG [Server 798a9538243b45b09052] pn=1 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 1280
server  |   -> RX Padding { len: 904 }
server  |   -> RX Crypto { offset: 0, len: 272 }
server  | 1.031 DEBUG Read Ok(272) bytes
server  | 1.031 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.031 DEBUG Read secret available for Handshake: SymKey [32]: 9b32447134a98e30c5ad32cce83b464542d1f2e7d3ee0fefcd29904a786a5bf2
server  | 1.031 DEBUG Write secret available for Handshake: SymKey [32]: e543a554f3cc917f52dc24c28994fe8bc2848acdc97466717d2fc511feef138c
server  | 1.031 DEBUG Writing transport parameters, msg=8
server  | 1.032 DEBUG Read secret available for ApplicationData: SymKey [32]: 5af6f54601caa9b4ced7c603b2ffa745b0ab643ef09dd47a07f207896a687e39
server  | 1.032 DEBUG Write secret available for ApplicationData: SymKey [32]: 16c41c40ac446b2605ede92569c29d2d5814dbe5076e7b07d340e0ca8e82b6ef
server  | 1.032 DEBUG [Agent 0x5585b875e7e0] 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: 324, tv_nsec: 593522503 }
server  | 1.032 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:45810] Make permanent
server  | 1.032 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:45810] set as primary path
server  | 1.032 DEBUG [Server 798a9538243b45b09052] State change from WaitInitial -> Handshaking
server  | 1.032 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG CRYPTO for in offset=0, len=90
server  | 1.032 DEBUG [Server 798a9538243b45b09052] pn=0 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 136
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   TX -> Crypto { offset: 0, len: 90 }
server  | 1.032 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG CRYPTO for hs offset=0, len=750
server  | 1.032 DEBUG [Server 798a9538243b45b09052] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 926
server  |   TX -> Crypto { offset: 0, len: 750 }
server  | 1.032 DEBUG packet_sent this=0x5585b8767b40, pn=0, ps=790
server  | 1.032 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.032 DEBUG [Server 798a9538243b45b09052] pad Initial from 926 to PLPMTU 1232
server  | 1.032 DEBUG packet_sent this=0x5585b8767b40, pn=0, ps=442
server  | 1.032 DEBUG ECN probing: sent 1 probes
server  | 1.032 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG [Server 798a9538243b45b09052] delay duration 297.173855ms
server  | 1.032 DEBUG Setting timeout of 297.173855ms
server  | 1.032 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.032 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.032 DEBUG [Server 798a9538243b45b09052] delay duration 297.143688ms
server  | 1.032 DEBUG Setting timeout of 297.143688ms
server  | 1.065 DEBUG [Server 798a9538243b45b09052] pn=2 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 1204
server  |   -> RX 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  |   -> RX Padding { len: 1096 }
server  | 1.065 DEBUG [Server 798a9538243b45b09052] Rx ACK space=in, ranges=[0..=0]
server  | 1.065 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.065 DEBUG on_packets_acked this=0x5585b8767b40, limited=1, bytes_in_flight=790, cwnd=12320, state=SlowStart, new_acked=442
server  | 1.065 DEBUG Acked crypto frame space=in offset=0 length=90
server  | 1.065 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:45810] Path validated Instant { tv_sec: 324, tv_nsec: 629637684 }
server  | 1.065 DEBUG [Server 798a9538243b45b09052] Drop packet number space in
server  | 1.065 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.065 DEBUG [Server 798a9538243b45b09052] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 76
server  |   -> RX Crypto { offset: 0, len: 36 }
server  | 1.065 DEBUG Read Ok(36) bytes
server  | 1.065 DEBUG [Agent 0x5585b875e7e0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
server  | 1.065 DEBUG [Server 798a9538243b45b09052] TLS connection complete
server  | 1.065 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:45810] Path validated Instant { tv_sec: 324, tv_nsec: 629637684 }
server  | 1.065 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.066 DEBUG [Crypto] application read keys installed
server  | 1.066 DEBUG [Server 798a9538243b45b09052] State change from Handshaking -> Connected
server  | 1.066 DEBUG [Server 798a9538243b45b09052] State change from Connected -> Confirmed
server  | 1.066 DEBUG PMTUD started with probe size 1380
server  | 1.066 INFO [Server 798a9538243b45b09052] Connection established
server  | 1.066 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 324, tv_nsec: 629637684 }
server  | 1.066 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: ce920e958ba2c02a439f)
server  | 1.066 DEBUG [Server 798a9538243b45b09052] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 41
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.066 DEBUG [Server 798a9538243b45b09052] Drop packet number space hs
server  | 1.066 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG [Server 798a9538243b45b09052] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [138, 19, 107, 208, 28, 204, 125, 33, 111, 61], stateless_reset_token: [124, 58, 81, 175, 220, 31, 168, 106, 33, 191, 240, 235, 75, 144, 176, 13] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [161, 5, 150, 123, 8, 72, 228, 228, 92, 98], stateless_reset_token: [230, 201, 242, 66, 43, 74, 129, 220, 58, 81, 116, 218, 238, 150, 234, 141] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [90, 89, 170, 115, 227, 139, 222, 77, 91, 179], stateless_reset_token: [152, 154, 121, 145, 132, 21, 171, 135, 244, 211, 239, 198, 94, 249, 227, 147] }
server  |   TX -> Padding { len: 1182 }
server  | 1.066 DEBUG packet_sent this=0x5585b8767b40, pn=0, ps=1291
server  | 1.066 DEBUG ECN probing: sent 2 probes
server  | 1.066 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.066 DEBUG [Server 798a9538243b45b09052] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1313 }
server  | 1.066 DEBUG packet_sent this=0x5585b8767b40, pn=1, ps=1332
server  | 1.066 DEBUG ECN probing: sent 3 probes
server  | 1.066 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG [Server 798a9538243b45b09052] delay duration 1.502931ms
server  | 1.066 DEBUG Setting timeout of 1.502931ms
server  | 1.066 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1
server  | 1.066 DEBUG [Server 798a9538243b45b09052] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 48
server  |   -> RX Stream { stream_id: 0, offset: 0, len: >>17, fin: true }
server  | 1.066 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 324, tv_nsec: 650205512 }
server  | 1.066 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG [Server 798a9538243b45b09052] delay duration 1.471251ms
server  | 1.066 DEBUG Setting timeout of 1.471251ms
server  | 1.067 DEBUG [Server 798a9538243b45b09052] send session ticket 407a0013a250d0fd226d79818fe31709a36be8c0d11a8e0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0ace920e958ba2c02a439f100a798a9538243b45b09052110c00000001ca2aaa0a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.067 DEBUG Path = 'pprafbdtug'
server  | 1.067 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG [Server 798a9538243b45b09052] delay duration 446.905µs
server  | 1.067 DEBUG Setting timeout of 446.905µs
server  | 1.068 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.068 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.068 DEBUG [Server 798a9538243b45b09052] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false }
server  | 1.068 DEBUG packet_sent this=0x5585b8767b40, pn=2, ps=1232
server  | 1.068 DEBUG ECN probing: sent 4 probes
server  | 1.068 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG [Server 798a9538243b45b09052] delay duration 1.094169ms
server  | 1.068 DEBUG Setting timeout of 1.094169ms
server  | 1.068 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.068 DEBUG [Server 798a9538243b45b09052] delay duration 1.072889ms
server  | 1.068 DEBUG Setting timeout of 1.072889ms
server  | 1.070 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG [Server 798a9538243b45b09052] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false }
server  | 1.070 DEBUG packet_sent this=0x5585b8767b40, pn=3, ps=1232
server  | 1.070 DEBUG ECN probing: sent 5 probes
server  | 1.070 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG [Server 798a9538243b45b09052] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false }
server  | 1.070 DEBUG packet_sent this=0x5585b8767b40, pn=4, ps=1232
server  | 1.070 DEBUG ECN probing: sent 6 probes
server  | 1.070 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.070 DEBUG [Server 798a9538243b45b09052] delay duration 1.699617ms
server  | 1.070 DEBUG Setting timeout of 1.699617ms
server  | 1.070 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.070 DEBUG [Server 798a9538243b45b09052] delay duration 1.677816ms
server  | 1.070 DEBUG Setting timeout of 1.677816ms
server  | 1.073 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.073 DEBUG [Server 798a9538243b45b09052] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false }
server  | 1.073 DEBUG packet_sent this=0x5585b8767b40, pn=5, ps=1232
server  | 1.073 DEBUG ECN probing: sent 7 probes
server  | 1.073 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.073 DEBUG [Server 798a9538243b45b09052] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4842, len: >>1210, fin: false }
server  | 1.073 DEBUG packet_sent this=0x5585b8767b40, pn=6, ps=1232
server  | 1.074 DEBUG ECN probing: sent 8 probes
server  | 1.074 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.074 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.074 DEBUG [Server 798a9538243b45b09052] delay duration 1.750856ms
server  | 1.074 DEBUG Setting timeout of 1.750856ms
server  | 1.074 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.074 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.074 DEBUG [Server 798a9538243b45b09052] delay duration 1.733934ms
server  | 1.074 DEBUG Setting timeout of 1.733934ms
server  | 1.076 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG [Server 798a9538243b45b09052] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 6052, len: >>1210, fin: false }
server  | 1.076 DEBUG packet_sent this=0x5585b8767b40, pn=7, ps=1232
server  | 1.076 DEBUG ECN probing: sent 9 probes
server  | 1.076 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.076 DEBUG [Server 798a9538243b45b09052] delay duration 1.389127ms
server  | 1.076 DEBUG Setting timeout of 1.389127ms
server  | 1.076 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.076 DEBUG [Server 798a9538243b45b09052] delay duration 1.367496ms
server  | 1.076 DEBUG Setting timeout of 1.367496ms
server  | 1.078 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG [Server 798a9538243b45b09052] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 7262, len: >>1210, fin: false }
server  | 1.078 DEBUG packet_sent this=0x5585b8767b40, pn=8, ps=1232
server  | 1.078 DEBUG ECN probing: sent 10 probes
server  | 1.078 DEBUG ECN probing concluded with 10 probes sent
server  | 1.078 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1073, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG [Server 798a9538243b45b09052] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 1073
server  |   TX -> Stream { stream_id: 0, offset: 8472, len: >>1051, fin: false }
server  | 1.078 DEBUG packet_sent this=0x5585b8767b40, pn=9, ps=1073
server  | 1.078 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server 798a9538243b45b09052] delay duration 7.911192ms
server  | 1.078 DEBUG Setting timeout of 7.911192ms
server  | 1.078 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server 798a9538243b45b09052] delay duration 7.889912ms
server  | 1.078 DEBUG Setting timeout of 7.889912ms
server  | 1.087 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.087 DEBUG [Server 798a9538243b45b09052] pn=10 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 24
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 2648, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.087 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG [Server 798a9538243b45b09052] delay duration 125.110402ms
server  | 1.087 DEBUG Setting timeout of 125.110402ms
server  | 1.087 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG [Server 798a9538243b45b09052] delay duration 125.088862ms
server  | 1.087 DEBUG Setting timeout of 125.088862ms
server  | 1.098 DEBUG [Server 798a9538243b45b09052] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 39
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 18, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  |   -> RX RetireConnectionId { sequence_number: 0 }
server  | 1.098 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=0]
server  | 1.098 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
server  | 1.098 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11029/13611 ssthresh 18446744073709551615] slow start += 1291
server  | 1.098 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11029/13611 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=11029, cwnd=13611, state=SlowStart, new_acked=1291
server  | 1.098 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 324, tv_nsec: 681960454 }
server  | 1.098 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG CRYPTO for ap offset=0, len=337
server  | 1.098 DEBUG [Server 798a9538243b45b09052] pn=11 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 1157
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [198, 151, 14, 109, 64, 46, 206, 104, 160, 102], stateless_reset_token: [77, 152, 151, 124, 200, 48, 252, 225, 47, 122, 145, 95, 198, 9, 132, 37] }
server  |   TX -> Stream { stream_id: 0, offset: 9523, len: 717, fin: true }
server  |   TX -> Crypto { offset: 0, len: 337 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 33, 166, 214, 39, 53, 8, 182, 110, 117, 149, 249, 251, 89, 45, 134, 45, 138, 155, 197, 67, 61, 154, 135, 109, 193, 34, 135, 44, 142, 112, 43, 22, 104, 99, 67, 197] }
server  | 1.098 DEBUG packet_sent this=0x5585b8767b40, pn=11, ps=1157
server  | 1.098 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG [Server 798a9538243b45b09052] delay duration 19.835771ms
server  | 1.098 DEBUG Setting timeout of 19.835771ms
server  | 1.098 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG [Server 798a9538243b45b09052] delay duration 19.80859ms
server  | 1.098 DEBUG Setting timeout of 19.80859ms
server  | 1.100 DEBUG [Server 798a9538243b45b09052] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 37
server  |   -> RX Ack { largest_acknowledged: 2, ack_delay: 6, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  | 1.100 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=2]
server  | 1.100 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2
server  | 1.100 INFO ECN validation succeeded, path is capable
server  | 1.100 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9622/16175 ssthresh 18446744073709551615] slow start += 2564
server  | 1.100 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9622/16175 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=9622, cwnd=16175, state=SlowStart, new_acked=2564
server  | 1.100 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.100 DEBUG PMTUD started with probe size 1420
server  | 1.100 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.100 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.100 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.100 DEBUG [Server 798a9538243b45b09052] pn=12 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1353 }
server  | 1.100 DEBUG packet_sent this=0x5585b8767b40, pn=12, ps=1372
server  | 1.100 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.100 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG [Server 798a9538243b45b09052] delay duration 17.976915ms
server  | 1.100 DEBUG Setting timeout of 17.976915ms
server  | 1.100 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.100 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG [Server 798a9538243b45b09052] delay duration 17.930478ms
server  | 1.100 DEBUG Setting timeout of 17.930478ms
server  | 1.103 DEBUG [Server 798a9538243b45b09052] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 37
server  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 6, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) }
server  | 1.103 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=4]
server  | 1.103 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4
server  | 1.103 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8530/18639 ssthresh 18446744073709551615] slow start += 2464
server  | 1.103 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8530/18639 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=8530, cwnd=18639, state=SlowStart, new_acked=2464
server  | 1.103 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.103 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.103 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.103 DEBUG [Server 798a9538243b45b09052] delay duration 14.937969ms
server  | 1.103 DEBUG Setting timeout of 14.937969ms
server  | 1.103 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.103 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.103 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.103 DEBUG [Server 798a9538243b45b09052] delay duration 14.888677ms
server  | 1.103 DEBUG Setting timeout of 14.888677ms
server  | 1.106 DEBUG [Server 798a9538243b45b09052] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 37
server  |   -> RX Ack { largest_acknowledged: 6, ack_delay: 7, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }
server  | 1.106 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=6]
server  | 1.106 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6
server  | 1.106 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6066/21103 ssthresh 18446744073709551615] slow start += 2464
server  | 1.106 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6066/21103 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=6066, cwnd=21103, state=SlowStart, new_acked=2464
server  | 1.106 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.106 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG [Server 798a9538243b45b09052] delay duration 11.645638ms
server  | 1.106 DEBUG Setting timeout of 11.645638ms
server  | 1.106 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.106 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG [Server 798a9538243b45b09052] delay duration 11.58844ms
server  | 1.106 DEBUG Setting timeout of 11.58844ms
server  | 1.109 DEBUG [Server 798a9538243b45b09052] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 37
server  |   -> RX Ack { largest_acknowledged: 8, ack_delay: 4, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  | 1.109 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=8]
server  | 1.109 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8
server  | 1.109 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3602/23567 ssthresh 18446744073709551615] slow start += 2464
server  | 1.109 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3602/23567 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=3602, cwnd=23567, state=SlowStart, new_acked=2464
server  | 1.109 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.109 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG [Server 798a9538243b45b09052] delay duration 8.274928ms
server  | 1.109 DEBUG Setting timeout of 8.274928ms
server  | 1.109 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.109 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG [Server 798a9538243b45b09052] delay duration 8.208904ms
server  | 1.109 DEBUG Setting timeout of 8.208904ms
server  | 1.118 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.118 DEBUG [Server 798a9538243b45b09052] pn=13 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 27
server  |   TX -> Ack { largest_acknowledged: 5, ack_delay: 1142, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) }
server  | 1.119 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.119 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.119 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.119 DEBUG [Server 798a9538243b45b09052] delay duration 67.451958ms
server  | 1.119 DEBUG Setting timeout of 67.451958ms
server  | 1.119 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.119 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.119 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.119 DEBUG [Server 798a9538243b45b09052] delay duration 67.427131ms
server  | 1.119 DEBUG Setting timeout of 67.427131ms
server  | 1.129 DEBUG [Server 798a9538243b45b09052] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 37
server  |   -> RX Ack { largest_acknowledged: 11, ack_delay: 11, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  | 1.129 DEBUG [Server 798a9538243b45b09052] Rx ACK space=ap, ranges=[0..=11]
server  | 1.129 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=11
server  | 1.129 WARN ECN validation failed, no ECT(0) packets were newly acked
server  | 1.129 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/25797 ssthresh 18446744073709551615] slow start += 2230
server  | 1.129 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/25797 ssthresh 18446744073709551615] on_packets_acked this=0x5585b8767b40, limited=0, bytes_in_flight=1372, cwnd=25797, state=SlowStart, new_acked=2230
server  | 1.129 DEBUG Acked crypto frame space=ap offset=0 length=337
server  | 1.129 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.129 DEBUG [Server 798a9538243b45b09052] pn=14 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 20
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.129 DEBUG packet_sent this=0x5585b8767b40, pn=14, ps=21
server  | 1.130 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.130 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.130 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.130 DEBUG [Server 798a9538243b45b09052] delay duration 81.881025ms
server  | 1.130 DEBUG Setting timeout of 81.881025ms
server  | 1.130 DEBUG [Server 798a9538243b45b09052] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, Ect0) len 32
server  |   -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" }
server  | 1.130 INFO [Server 798a9538243b45b09052] ConnectionClose received. Error code: Application(0) frame type 0 reason 
server  | 1.130 DEBUG [Server 798a9538243b45b09052] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 324, tv_nsec: 940026083 } }
server  | 1.130 DEBUG [Server 798a9538243b45b09052] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.130 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.130 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 324, tv_nsec: 693878600 }
server  | 1.130 DEBUG [Server 798a9538243b45b09052] pn=15 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:45810 IpTos(Cs0, NotEct) len 30
server  |   TX -> Ack { largest_acknowledged: 7, ack_delay: 0, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" }
server  | 1.130 DEBUG Setting timeout of 245.915707ms
server  | 1.130 DEBUG Setting timeout of 245.902391ms

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 09:37:57,758 Using the client's key log file.
2025-04-30 09:37:57,767 
2025-04-30 09:37:57,767 Using the client's key log file.
2025-04-30 09:37:57,767 Using the client's key log file.
2025-04-30 09:37:57,775 
2025-04-30 09:37:57,776 Using the client's key log file.
2025-04-30 09:37:58,340 Check of downloaded files succeeded.
2025-04-30 09:37:58,912 Check of Retry succeeded. Token used: 526574727901006de99228a48c112ed6ea2b1df540beb09b40360cc235eb971da7a82cbad40af2a5ffd7b346b03d2ff82c89042d6a8e9b773d304092780b