2025-04-30 08:47:37,839 Generated random file: qzihrjyqau of size: 5120
2025-04-30 08:47:37,839 Generated random file: acmfnxbobw of size: 10240
2025-04-30 08:47:37,839 Requests: https://server6:443/qzihrjyqau https://server6:443/acmfnxbobw
2025-04-30 08:47:37,898 
2025-04-30 08:47:37,899 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_5_jjx0t_/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_w9w6abyt/ DOWNLOADS=/tmp/download_o23omr4g/ SERVER_LOGS=/tmp/logs_server__ifw2h_3 CLIENT_LOGS=/tmp/logs_client_gi7tt8ag 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://server6:443/qzihrjyqau https://server6:443/acmfnxbobw"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 08:47:50,431  Container sim  Recreate
 Container sim  Recreated
 Container client  Recreate
 Container server  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]
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
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
client  | Endpoint's IPv4 address is 193.167.0.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::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 transfer ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.G7axnOpkjw
server  | + mkdir -p /neqo/db
client  | x86_64
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.G7axnOpkjw
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.G7axnOpkjw -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  |             3c:03:99:ac:6f:15:8e:12:fa:6d:8c:3f:29:b4:9d:7c:
server  |             a5:7b:0f:29
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:47:37 2025
server  |             Not After : Sat May 10 08:47:37 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:8c:d7:a7:5a:67:29:50:c6:d6:d7:da:d8:25:b8:e0:
server  |                     aa:38:a3:0b:a3:10:a0:f9:ab:d0:34:a8:09:4d:14:da:
server  |                     db:32:a9:5c:e7:51:58:42:7b:73:f9:57:6a:52:4a:95:
server  |                     b0:a7:a7:61:84:6c:2d:cf:a9:e7:28:6c:fd:24:94:d6:
server  |                     22
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  |                 f3:ee:4d:28:9d:46:08:2b:ca:bc:c1:be:39:8b:75:b8:
server  |                 31:6e:da:ec
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 22:3a:d4:e0:dc:fc:a5:83:1a:39:f2:48:ab:9b:2b:2a:
server  |                 89:bd:69:e7
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:20:33:b9:a3:73:7a:00:6d:79:f2:07:19:1a:
server  |         7c:45:78:d4:d6:5a:62:a8:19:a5:fe:eb:a1:9e:f7:e7:
server  |         f2:18:84:3a:02:21:00:bd:0d:4c:9e:f2:b8:e8:ed:9b:
server  |         3c:52:bb:46:f8:54:71:7f:af:52:1d:0a:43:12:b2:e3:
server  |         7d:5b:66:e5:5e:2a:37
server  |     Fingerprint (SHA-256):
server  |         EF:D4:11:F2:02:9E:E2:79:E1:3C:78:77:9B:E8:12:BA:11:4C:45:E6:83:2F:14:6D:6A:4B:B1:FA:F6:E3:EC:9A
server  |     Fingerprint (SHA1):
server  |         25:47:36:A5:1B:67:5E:43:8D:FE:D9:FA:7C:1E:E2:2C:BC:08:28:34
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  | + '[' transfer = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test transfer --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.735 DEBUG [Server] Unsupported version: 57414954
server  | 0.735 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59478 IpTos(Cs0, NotEct) len 15
server  | 0.735 DEBUG [Server] Unsupported version: 57414954
server  | 0.735 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59478 IpTos(Cs0, NotEct) len 15
server  | 0.735 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.735 DEBUG [Server] Unsupported version: 57414954
server  | 0.735 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59478 IpTos(Cs0, NotEct) len 15
server  | 0.735 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | server:443 is available after 1.014192939s
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | connecting to server6 at [fd00:cafe:cafe:100:0:0:0:100]:443
server  | 1.045 DEBUG [Server] Handle initial
server  | 1.045 INFO AddressValidation: no token; accepting
server  | 1.045 INFO [Server] Accept connection CID [8]: 974a4d453f40b2d7
server  | 1.045 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.047 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500
server  | 1.047 INFO [Server ...] Received valid Initial packet with scid CID [16]: 059b5b88aa454415d132e4988773d3a0 dcid CID [8]: 974a4d453f40b2d7
server  | 1.047 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=974a4d453f40b2d7
server  | 1.047 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.047 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.047 DEBUG [Server 974a4d453f40b2d7] State change from Init -> WaitInitial
server  | 1.047 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   -> RX Crypto { offset: 0, len: 287 }
server  |   -> RX Padding { len: 890 }
server  | 1.047 DEBUG Read Ok(287) bytes
server  | 1.047 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.048 DEBUG Read secret available for Handshake: SymKey [32]: c6cda1f0d88a2644a36b16c8f3c6ee899f1d32c1a6f7b115b0c90df2d1c7f7ba
server  | 1.048 DEBUG Write secret available for Handshake: SymKey [32]: cfdd456f4eecc3375e08892a6ac30b8352c627185341bdf94994ac01e80e7ccb
server  | 1.048 DEBUG Writing transport parameters, msg=8
server  | 1.048 DEBUG Read secret available for ApplicationData: SymKey [32]: 457f1c72c262cd951530c1697716b0f31327973f8951e0aed1541eb6f3fc8c42
server  | 1.048 DEBUG Write secret available for ApplicationData: SymKey [32]: 674e5067cb73013dd0f63119416ab11e5812cfa445d2346b954b40f645654b91
server  | 1.048 DEBUG [Agent 0x5621800751d0] state -> InProgress
server  | 1.048 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.048 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.048 DEBUG [Crypto] Handshake keys installed
server  | 1.048 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.048 DEBUG [Crypto] Application write key installed
server  | 1.048 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 522, tv_nsec: 831618439 }
server  | 1.048 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:38815] Make permanent
server  | 1.048 DEBUG [unv-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815] set as primary path
server  | 1.048 DEBUG [Server 974a4d453f40b2d7] State change from WaitInitial -> Handshaking
server  | 1.048 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.048 DEBUG Building Initial dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.048 DEBUG CRYPTO for in offset=0, len=123
server  | 1.048 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Initial pri-unv-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 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.048 DEBUG Building Handshake dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.048 DEBUG CRYPTO for hs offset=0, len=725
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Handshake pri-unv-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 969
server  |   TX -> Crypto { offset: 0, len: 725 }
server  | 1.049 DEBUG packet_sent this=0x562180074b40, pn=0, ps=781
server  | 1.049 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] pad Initial from 969 to PLPMTU 1232
server  | 1.049 DEBUG packet_sent this=0x562180074b40, pn=0, ps=451
server  | 1.049 DEBUG ECN probing: sent 1 probes
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Initial dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.049 DEBUG Building Handshake dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.049 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] delay duration 296.802046ms
server  | 1.049 DEBUG Setting timeout of 296.802046ms
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Initial dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.049 DEBUG Building Handshake dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.049 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server 974a4d453f40b2d7] delay duration 296.766019ms
server  | 1.049 DEBUG Setting timeout of 296.766019ms
client  | GET /qzihrjyqau
client  | GET /acmfnxbobw
server  | 1.083 DEBUG [Server 974a4d453f40b2d7] pn=1 type=Initial pri-unv-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 72
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 1748, 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.083 DEBUG [Server 974a4d453f40b2d7] Rx ACK space=in, ranges=[0..=0]
server  | 1.083 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.083 DEBUG on_packets_acked this=0x562180074b40, limited=1, bytes_in_flight=781, cwnd=12320, state=SlowStart, new_acked=451
server  | 1.084 DEBUG Acked crypto frame space=in offset=0 length=123
server  | 1.084 DEBUG [pri-unv-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815] Path validated Instant { tv_sec: 522, tv_nsec: 869696655 }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] Drop packet number space in
server  | 1.084 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Handshake pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1160
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 1748, 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: 1060 }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] Rx ACK space=hs, ranges=[0..=0]
server  | 1.084 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.084 DEBUG on_packets_acked this=0x562180074b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=781
server  | 1.084 DEBUG Acked crypto frame space=hs offset=0 length=725
server  | 1.084 DEBUG Read Ok(36) bytes
server  | 1.084 DEBUG [Agent 0x5621800751d0] 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.084 DEBUG [Server 974a4d453f40b2d7] TLS connection complete
server  | 1.084 DEBUG [pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815] Path validated Instant { tv_sec: 522, tv_nsec: 869696655 }
server  | 1.084 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.084 DEBUG [Crypto] application read keys installed
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] State change from Handshaking -> Connected
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] State change from Connected -> Confirmed
server  | 1.084 DEBUG PMTUD started with probe size 1380
server  | 1.084 INFO [Server 974a4d453f40b2d7] Connection established
server  | 1.084 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 522, tv_nsec: 869696655 }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.084 DEBUG Building Handshake dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0) scid Some(CID [10]: bff9fdbbcecdcd763030)
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] pn=1 type=Handshake pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 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.084 DEBUG [Server 974a4d453f40b2d7] Drop packet number space hs
server  | 1.084 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.084 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [87, 17, 96, 65, 35, 163, 201, 121, 146, 141], stateless_reset_token: [30, 35, 248, 40, 189, 176, 168, 197, 253, 15, 226, 78, 10, 192, 36, 40] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [204, 61, 220, 25, 94, 84, 12, 67, 98, 85], stateless_reset_token: [89, 106, 225, 194, 7, 228, 143, 219, 201, 168, 210, 223, 50, 34, 106, 155] }
server  |   TX -> Padding { len: 1177 }
server  | 1.084 DEBUG packet_sent this=0x562180074b40, pn=0, ps=1272
server  | 1.084 DEBUG ECN probing: sent 2 probes
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.084 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.084 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] pn=1 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1297 }
server  | 1.084 DEBUG packet_sent this=0x562180074b40, pn=1, ps=1332
server  | 1.084 DEBUG ECN probing: sent 3 probes
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.084 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] delay duration 1.455959ms
server  | 1.084 DEBUG Setting timeout of 1.455959ms
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] pn=0 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 71
server  |   -> RX Stream { stream_id: 4, offset: 0, len: 0, fin: false }
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  |   -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true }
server  | 1.084 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 522, tv_nsec: 890397644 }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.084 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.084 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.084 DEBUG [Server 974a4d453f40b2d7] delay duration 1.419802ms
server  | 1.084 DEBUG Setting timeout of 1.419802ms
server  | 1.085 DEBUG [Server 974a4d453f40b2d7] send session ticket 40630008974a4d453f40b2d70104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0abff9fdbbcecdcd763030110c000000016a5a8a0a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.085 DEBUG Path = 'qzihrjyqau'
server  | 1.085 DEBUG Path = 'acmfnxbobw'
server  | 1.085 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.085 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.085 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.085 DEBUG [Server 974a4d453f40b2d7] delay duration 293.097µs
server  | 1.085 DEBUG Setting timeout of 293.097µs
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] pn=2 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1196, fin: false }
server  | 1.087 DEBUG packet_sent this=0x562180074b40, pn=2, ps=1232
server  | 1.087 DEBUG ECN probing: sent 4 probes
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] pn=3 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1196, len: >>1194, fin: false }
server  | 1.087 DEBUG packet_sent this=0x562180074b40, pn=3, ps=1232
server  | 1.087 DEBUG ECN probing: sent 5 probes
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.087 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] delay duration 1.852243ms
server  | 1.087 DEBUG Setting timeout of 1.852243ms
server  | 1.087 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.087 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.088 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.088 DEBUG [Server 974a4d453f40b2d7] delay duration 1.837075ms
server  | 1.088 DEBUG Setting timeout of 1.837075ms
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.091 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] pn=4 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2390, len: >>1194, fin: false }
server  | 1.091 DEBUG packet_sent this=0x562180074b40, pn=4, ps=1232
server  | 1.091 DEBUG ECN probing: sent 6 probes
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.091 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] pn=5 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3584, len: >>1194, fin: false }
server  | 1.091 DEBUG packet_sent this=0x562180074b40, pn=5, ps=1232
server  | 1.091 DEBUG ECN probing: sent 7 probes
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.091 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.091 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] delay duration 1.829463ms
server  | 1.091 DEBUG Setting timeout of 1.829463ms
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.091 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.091 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.091 DEBUG [Server 974a4d453f40b2d7] delay duration 1.780041ms
server  | 1.091 DEBUG Setting timeout of 1.780041ms
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] pn=6 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4778, len: 342, fin: true }
server  |   TX -> Stream { stream_id: 4, offset: 0, len: >>848, fin: false }
server  | 1.094 DEBUG packet_sent this=0x562180074b40, pn=6, ps=1232
server  | 1.094 DEBUG ECN probing: sent 8 probes
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] pn=7 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 848, len: >>1194, fin: false }
server  | 1.094 DEBUG packet_sent this=0x562180074b40, pn=7, ps=1232
server  | 1.094 DEBUG ECN probing: sent 9 probes
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.094 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.094 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] delay duration 1.830821ms
server  | 1.094 DEBUG Setting timeout of 1.830821ms
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.094 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.094 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.094 DEBUG [Server 974a4d453f40b2d7] delay duration 1.804893ms
server  | 1.094 DEBUG Setting timeout of 1.804893ms
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] pn=8 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 2042, len: >>1194, fin: false }
server  | 1.097 DEBUG packet_sent this=0x562180074b40, pn=8, ps=1232
server  | 1.097 DEBUG ECN probing: sent 10 probes
server  | 1.097 DEBUG ECN probing concluded with 10 probes sent
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1092, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] pn=9 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 1092
server  |   TX -> Stream { stream_id: 4, offset: 3236, len: >>1054, fin: false }
server  | 1.097 DEBUG packet_sent this=0x562180074b40, pn=9, ps=1092
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] delay duration 6.857367ms
server  | 1.097 DEBUG Setting timeout of 6.857367ms
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG [Server 974a4d453f40b2d7] delay duration 6.838151ms
server  | 1.097 DEBUG Setting timeout of 6.838151ms
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] pn=10 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 43
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 2656, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] delay duration 111.961157ms
server  | 1.105 DEBUG Setting timeout of 111.961157ms
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server 974a4d453f40b2d7] delay duration 111.937873ms
server  | 1.105 DEBUG Setting timeout of 111.937873ms
client  | Request /qzihrjyqau completed successfully
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] pn=1 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1452
server  |   -> RX Ping
server  |   -> RX Padding { len: 1423 }
server  | 1.118 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 522, tv_nsec: 904150419 }
server  | 1.118 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 522, tv_nsec: 904150419 }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] pn=11 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 42
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] delay duration 99.430949ms
server  | 1.118 DEBUG Setting timeout of 99.430949ms
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 059b5b88aa454415d132e4988773d3a0)
server  | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] delay duration 99.399801ms
server  | 1.118 DEBUG Setting timeout of 99.399801ms
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] pn=2 type=Short pri-path:059b5b88aa454415d132e4988773d3a0 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 147
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 86, 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: [99, 122, 172, 179, 159, 43, 126, 241, 236, 249, 255, 242, 66, 1, 9, 68], stateless_reset_token: [18, 231, 66, 165, 88, 47, 12, 165, 182, 80, 75, 229, 45, 46, 192, 236] }
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 1, connection_id: [195, 179, 106, 173, 177, 73, 180, 96, 81, 176, 31, 33, 128, 198, 175, 216], stateless_reset_token: [159, 197, 238, 48, 229, 41, 6, 152, 107, 238, 71, 15, 206, 197, 32, 19] }
server  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 1, connection_id: [253, 16, 137, 201, 88, 199, 124, 155, 58, 243, 233, 157, 187, 144, 122, 180], stateless_reset_token: [167, 157, 242, 222, 236, 151, 170, 183, 201, 169, 229, 208, 87, 165, 79, 178] }
server  |   -> RX RetireConnectionId { sequence_number: 0 }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] Rx ACK space=ap, ranges=[0..=0]
server  | 1.118 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
server  | 1.118 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11048/13592 ssthresh 18446744073709551615] slow start += 1272
server  | 1.118 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11048/13592 ssthresh 18446744073709551615] on_packets_acked this=0x562180074b40, limited=0, bytes_in_flight=11048, cwnd=13592, state=SlowStart, new_acked=1272
server  | 1.118 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 522, tv_nsec: 924303345 }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] pn=12 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 1232
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [68, 246, 119, 59, 49, 142, 215, 219, 89, 229], stateless_reset_token: [230, 167, 226, 161, 1, 241, 157, 39, 114, 207, 87, 20, 21, 255, 69, 78] }
server  |   TX -> RetireConnectionId { sequence_number: 0 }
server  |   TX -> Stream { stream_id: 4, offset: 4290, len: >>1162, fin: false }
server  | 1.118 DEBUG packet_sent this=0x562180074b40, pn=12, ps=1232
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] pn=13 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 5452, len: >>1194, fin: false }
server  | 1.118 DEBUG packet_sent this=0x562180074b40, pn=13, ps=1232
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] delay duration 19.682159ms
server  | 1.118 DEBUG Setting timeout of 19.682159ms
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.118 DEBUG [Server 974a4d453f40b2d7] delay duration 19.657021ms
server  | 1.118 DEBUG Setting timeout of 19.657021ms
server  | 1.138 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.139 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.139 DEBUG [Server 974a4d453f40b2d7] pn=14 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, NotEct) len 43
server  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 2554, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  | 1.139 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.139 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.139 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.139 DEBUG [Server 974a4d453f40b2d7] delay duration 88.661111ms
server  | 1.139 DEBUG Setting timeout of 88.661111ms
server  | 1.139 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.139 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.139 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.139 DEBUG [Server 974a4d453f40b2d7] delay duration 88.633409ms
server  | 1.139 DEBUG Setting timeout of 88.633409ms
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] pn=3 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 47
server  |   -> RX Ack { largest_acknowledged: 10, ack_delay: 817, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  |   -> RX Padding { len: 10 }
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] Rx ACK space=ap, ranges=[0..=10]
server  | 1.143 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10
server  | 1.143 INFO ECN validation succeeded, path is capable
server  | 1.143 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2464/24640 ssthresh 18446744073709551615] slow start += 11048
server  | 1.143 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2464/24640 ssthresh 18446744073709551615] on_packets_acked this=0x562180074b40, limited=0, bytes_in_flight=2464, cwnd=24640, state=SlowStart, new_acked=11048
server  | 1.143 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.143 DEBUG PMTUD started with probe size 1420
server  | 1.143 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] pn=15 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  |   TX -> Stream { stream_id: 4, offset: 6646, len: >>1331, fin: false }
server  | 1.143 DEBUG packet_sent this=0x562180074b40, pn=15, ps=1372
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] pn=16 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 7977, len: >>1294, fin: false }
server  | 1.143 DEBUG packet_sent this=0x562180074b40, pn=16, ps=1332
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG CRYPTO for ap offset=0, len=305
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] pn=17 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1318
server  |   TX -> Stream { stream_id: 4, offset: 9271, len: 969, fin: true }
server  |   TX -> Crypto { offset: 0, len: 305 }
server  | 1.143 DEBUG packet_sent this=0x562180074b40, pn=17, ps=1318
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] pn=18 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 79
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 252, 223, 167, 171, 166, 233, 60, 217, 73, 173, 82, 45, 97, 151, 136, 198, 15, 203, 17, 127, 162, 149, 239, 93, 13, 84, 124, 60, 128, 202, 88, 67, 245, 15, 55, 203] }
server  | 1.143 DEBUG packet_sent this=0x562180074b40, pn=18, ps=79
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] delay duration 97.509083ms
server  | 1.143 DEBUG Setting timeout of 97.509083ms
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.143 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.143 DEBUG [Server 974a4d453f40b2d7] delay duration 97.479908ms
server  | 1.143 DEBUG Setting timeout of 97.479908ms
client  | Request /acmfnxbobw completed successfully
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] pn=5 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 47
server  |   -> RX Ack { largest_acknowledged: 15, ack_delay: 24, first_ack_range: 14, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) }
server  |   -> RX Padding { len: 11 }
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] Rx ACK space=ap, ranges=[1..=15]
server  | 1.175 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=15
server  | 1.175 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2729/28476 ssthresh 18446744073709551615] slow start += 3836
server  | 1.175 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2729/28476 ssthresh 18446744073709551615] on_packets_acked this=0x562180074b40, limited=0, bytes_in_flight=2729, cwnd=28476, state=SlowStart, new_acked=3836
server  | 1.175 DEBUG PMTUD probe of size 1420 succeeded
server  | 1.175 DEBUG PMTUD started with probe size 1470
server  | 1.175 DEBUG PLPMTU changed from 1332 to 1372, updating pacer
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.175 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.175 DEBUG Sending PMTUD probe of size 1470, count 1
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] pn=19 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 1422
server  |   TX -> Ping
server  |   TX -> Padding { len: 1387 }
server  | 1.175 DEBUG packet_sent this=0x562180074b40, pn=19, ps=1422
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.175 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.175 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] delay duration 93.365228ms
server  | 1.175 DEBUG Setting timeout of 93.365228ms
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.175 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.175 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.175 DEBUG [Server 974a4d453f40b2d7] delay duration 93.327928ms
server  | 1.175 DEBUG Setting timeout of 93.327928ms
server  | 1.178 DEBUG [Server 974a4d453f40b2d7] pn=6 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 47
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  |   -> RX Padding { len: 15 }
server  | 1.178 INFO [Server 974a4d453f40b2d7] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.178 DEBUG [Server 974a4d453f40b2d7] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 523, tv_nsec: 244627315 } }
server  | 1.178 DEBUG [Server 974a4d453f40b2d7] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.178 DEBUG Building Short dcid Some(CID [16]: 637aacb39f2b7ef1ecf9fff242010944)
server  | 1.178 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 522, tv_nsec: 964084424 }
server  | 1.178 DEBUG [Server 974a4d453f40b2d7] pn=20 type=Short pri-path:637aacb39f2b7ef1ecf9fff242010944 [::]:443->[fd00:cafe:cafe::100]:38815 IpTos(Cs0, Ect0) len 48
server  |   TX -> Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 3 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 1.178 DEBUG Setting timeout of 280.453971ms
server  | 1.178 DEBUG Setting timeout of 280.441578ms
server  | 1.260 WARN [Server ...] Dropped received packet: State Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 523, tv_nsec: 244627315 } }; Total: 1
server  | 1.260 DEBUG Setting timeout of 197.957649ms
server  | 1.260 DEBUG Setting timeout of 197.930208ms
server  | 1.460 DEBUG [Server 974a4d453f40b2d7] State change from Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 523, tv_nsec: 244627315 } } -> Closed(Transport(PeerError(0)))
server  | 1.460 INFO Closing timer expired

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

2025-04-30 08:47:50,534 Using the client's key log file.
2025-04-30 08:47:50,544 
2025-04-30 08:47:50,545 Using the client's key log file.
2025-04-30 08:47:50,545 Using the client's key log file.
2025-04-30 08:47:50,555 
2025-04-30 08:47:50,556 Using the client's key log file.
2025-04-30 08:47:51,144 Check of downloaded files succeeded.
2025-04-30 08:47:51,733 Check of downloaded files succeeded.