2025-09-11 19:45:06,601 Generated random file: ziwpgrtihw of size: 1024 2025-09-11 19:45:06,601 Requests: https://server4:443/ziwpgrtihw 2025-09-11 19:45:06,661 2025-09-11 19:45:06,662 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_vho63nzu/ TESTCASE_SERVER=ecn TESTCASE_CLIENT=ecn WWW=/tmp/www_ovfb0fps/ DOWNLOADS=/tmp/download_tetz7rx2/ SERVER_LOGS=/tmp/logs_server_mejjlz8e CLIENT_LOGS=/tmp/logs_client_hkus9d1y SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/ziwpgrtihw" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-09-11 19:45:18,895 Container client Recreate Container server Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n ecn ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 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 ecn ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.NaFL2wS3Iy server | + mkdir -p /neqo/db client | wait-for-it.sh: waiting 30 seconds for sim:57832 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.NaFL2wS3Iy server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.NaFL2wS3Iy -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 | 7b:1c:dd:3c:a8:38:62:09:3c:2b:ab:89:11:f3:ad:d5: server | 15:02:0e:95 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Thu Sep 11 19:45:06 2025 server | Not After : Sun Sep 21 19:45:06 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:bd:3d:c7:56:55:63:d4:54:3a:67:50:17:90:a3:76: server | ea:87:bb:aa:c5:1f:4e:b3:e1:21:1d:5a:1d:fa:e4:08: server | 7c:a7:77:85:76:75:99:7a:2a:46:76:35:1d:9b:6a:df: server | cb:ff:0c:f5:bd:c2:c8:f1:33:99:65:5a:f1:43:98:65: server | 68 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 | c1:9d:49:b5:b0:da:39:8b:6c:4a:28:fe:4b:5c:4b:bf: server | da:f6:bb:85 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 74:18:0f:b4:34:67:0a:06:9e:94:0e:8b:63:5b:ad:e1: server | d8:c4:15:86 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:21:00:f3:8f:f2:95:00:c4:fa:75:c8:aa:3d: server | 5b:27:ae:d8:20:ab:bb:71:b4:4a:80:40:d8:a7:65:97: server | 77:96:e2:e5:95:02:20:59:d6:b6:ac:6c:94:e1:7d:17: server | ea:06:95:0f:0b:71:ac:19:17:13:1e:4b:65:c7:50:58: server | 8e:13:59:19:64:df:95 server | Fingerprint (SHA-256): server | 5B:21:38:AB:34:9B:30:CC:82:FC:6A:FE:74:AA:C5:4C:B9:0B:3F:EE:49:76:DA:9C:91:EB:C2:A0:61:5C:91:0B server | Fingerprint (SHA1): server | C3:4B:73:54:1D:22:64:EC:1C:EE:FA:86:37:F1:40:F7:67:36:B7:D4 server | server | Mozilla-CA-Policy: false (attribute missing) server | Certificate Trust Flags: server | SSL Flags: server | User server | Email Flags: server | User server | Object Signing Flags: server | User server | server | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT") server | + '[' ecn = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test ecn --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443' server | ++ tee -i -a /logs/server.log server | 0.000 DEBUG Logging initialized server | 0.002 DEBUG Default socket send buffer size is Ok(212992) server | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.002 INFO Server waiting for connection on: Ok([::]:443) server | 0.299 DEBUG [Server] Unsupported version: 57414954 server | 0.299 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:41594 Tos(Cs0, NotEct) len 15 sim | server:443 is available after 501.282444ms 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 | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' https://server4:443/ziwpgrtihw ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test ecn --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/ziwpgrtihw client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.000 DEBUG Default socket send buffer size is Ok(212992) client | 0.000 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.000 INFO hq-interop Client connecting: 0.0.0.0:57267 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=f446104ad5025cb715904f1c8d client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=20 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:57267->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:f446104ad5025cb715904f1c8d 0.0.0.0:57267->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:f446104ad5025cb715904f1c8d 0.0.0.0:57267->193.167.100.100:443] Path validated Instant { tv_sec: 511, tv_nsec: 810137103 } client | 0.001 DEBUG [Client f446104ad5025cb715904f1c8d] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x557e033f6500] state -> InProgress client | 0.001 DEBUG [Client f446104ad5025cb715904f1c8d] State change from Init -> WaitInitial client | 0.001 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.001 DEBUG CRYPTO for in offset=0, len=1208 client | 0.001 DEBUG [Client f446104ad5025cb715904f1c8d] pn=20 type=Initial pri-path:f446104ad5025cb715904f1c8d 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1208 } client | 0.001 DEBUG packet_sent this=0x557e03409ad0, pn=20, ps=1252 client | 0.001 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1208, len=332 client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] pn=21 type=Initial pri-path:f446104ad5025cb715904f1c8d 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 377 client | TX -> Crypto { offset: 1208, len: 332 } client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] pad Initial from 377 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x557e03409ad0, pn=21, ps=1252 client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 3.883606ms client | 0.002 DEBUG Setting timeout of 3.883606ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 3.849562ms client | 0.002 DEBUG Setting timeout of 3.849562ms client | 0.007 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [13]: f446104ad5025cb715904f1c8d) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 294.307075ms client | 0.007 DEBUG Setting timeout of 294.307075ms server | 0.994 DEBUG [Server] Handle initial server | 0.994 INFO AddressValidation: no token; accepting server | 0.994 INFO [Server] Accept connection CID [13]: f446104ad5025cb715904f1c8d server | 0.994 DEBUG Overwrite initial version Version1 ==> Version1 server | 0.996 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 0.996 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [13]: f446104ad5025cb715904f1c8d server | 0.996 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=f446104ad5025cb715904f1c8d server | 0.996 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=8 server | 0.996 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] State change from Init -> WaitInitial server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] pn=20 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 1252 server | -> RX Crypto { offset: 0, len: 1208 } server | 0.996 DEBUG [Agent 0x560de2194650] state -> InProgress server | 0.996 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 832503254 } server | 0.996 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:57267] Make permanent server | 0.996 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:57267] set as primary path server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] State change from WaitInitial -> WaitVersion server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.996 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] pn=8 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 42 server | TX -> Ack { largest_acknowledged: 20, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.996 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.996 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 298.165396ms server | 0.996 DEBUG Setting timeout of 298.165396ms server | 0.996 DEBUG [Server f446104ad5025cb715904f1c8d] pn=21 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 377 server | -> RX Crypto { offset: 1208, len: 332 } server | 0.996 DEBUG 0-RTT: no token, no 0-RTT server | 0.997 DEBUG Read secret available for Handshake: SymKey [32]: 71489a6740765bcca17711d97142ff2701b71e55c918c43ef2a42a76135ac21e server | 0.997 DEBUG Write secret available for Handshake: SymKey [32]: c74aae6e95d90a276ec0c68ae81e2d85c71e00e1b4326b44b85d76cdd5065605 server | 0.997 DEBUG Writing transport parameters, msg=8 server | 0.997 DEBUG Read secret available for ApplicationData: SymKey [32]: 88ad1deddb7e2c8c8424f4255386711ebe931850cc712b0ca0df056a133a0a01 server | 0.997 DEBUG Write secret available for ApplicationData: SymKey [32]: 4b75834e8de7ed46cb9dfce01517f6b7e44f47e0096c1aa71765be671c4c1c90 server | 0.997 DEBUG [Agent 0x560de2194650] state -> InProgress server | 0.997 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 0.997 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 0.997 DEBUG [Crypto] Handshake keys installed server | 0.997 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 0.997 DEBUG [Crypto] Application write key installed server | 0.997 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 834371350 } server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] State change from WaitVersion -> Handshaking server | 0.997 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.997 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG CRYPTO for in offset=0, len=1178 server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] pn=9 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 1224 server | TX -> Ack { largest_acknowledged: 21, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 1178 } server | 0.997 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] pad Initial from 1224 to PLPMTU 1232 server | 0.997 DEBUG packet_sent this=0x560de21946d0, pn=9, ps=1232 server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.997 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG CRYPTO for hs offset=0, len=739 server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 779 server | TX -> Crypto { offset: 0, len: 739 } server | 0.997 DEBUG packet_sent this=0x560de21946d0, pn=0, ps=779 server | 0.997 DEBUG Building Short dcid Some(CID [0]: ) server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 0.997 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG Building Short dcid Some(CID [0]: ) server | 0.997 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 238.08µs server | 0.997 DEBUG Setting timeout of 238.08µs server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 0.997 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.997 DEBUG Building Short dcid Some(CID [0]: ) server | 0.997 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 0.997 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 204.728µs server | 0.997 DEBUG Setting timeout of 204.728µs server | 0.998 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.998 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.998 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.998 DEBUG Building Short dcid Some(CID [0]: ) server | 0.998 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.998 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 297.650082ms server | 0.998 DEBUG Setting timeout of 297.650082ms server | 0.998 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.998 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.998 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 0.998 DEBUG Building Short dcid Some(CID [0]: ) server | 0.998 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.998 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 297.620216ms server | 0.998 DEBUG Setting timeout of 297.620216ms client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] pn=8 type=Initial pri-path:f446104ad5025cb715904f1c8d 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 42 client | -> RX Ack { largest_acknowledged: 20, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] Rx ACK space=in, ranges=[20..=20] client | 0.040 DEBUG [recovery::Loss] ACK for Initial - largest_acked=20 client | 0.040 DEBUG on_packets_acked this=0x557e03409ad0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.040 DEBUG Acked crypto frame space=in offset=0 length=1208 client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] Changing to use Server CID=f455326c54256350e714 client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] State change from WaitInitial -> WaitVersion client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 77.659218ms client | 0.040 DEBUG Setting timeout of 77.659218ms client | 0.040 WARN Unhandled event StateChange(WaitVersion) client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 77.625755ms client | 0.040 DEBUG Setting timeout of 77.625755ms client | 0.042 DEBUG [Client f446104ad5025cb715904f1c8d] pn=9 type=Initial pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 1224 client | -> RX Ack { largest_acknowledged: 21, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 1178 } client | 0.042 DEBUG [Client f446104ad5025cb715904f1c8d] Rx ACK space=in, ranges=[20..=21] client | 0.042 DEBUG [recovery::Loss] ACK for Initial - largest_acked=21 client | 0.042 DEBUG on_packets_acked this=0x557e03409ad0, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.042 DEBUG Acked crypto frame space=in offset=1208 length=332 client | 0.043 DEBUG Write secret available for Handshake: SymKey [32]: 71489a6740765bcca17711d97142ff2701b71e55c918c43ef2a42a76135ac21e client | 0.043 DEBUG Read secret available for Handshake: SymKey [32]: c74aae6e95d90a276ec0c68ae81e2d85c71e00e1b4326b44b85d76cdd5065605 client | 0.043 DEBUG [Agent 0x557e033f6500] state -> InProgress client | 0.043 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.043 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.043 DEBUG [Crypto] Handshake keys installed client | 0.043 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 511, tv_nsec: 851731602 } client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] State change from WaitVersion -> Handshaking client | 0.043 INFO [Client f446104ad5025cb715904f1c8d] Garbage packet: an invalid packet was dropped (internal use only) client | 0.043 DEBUG [Client ...] Dropped received packet: Garbage packet; Total: 1 client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] pn=22 type=Initial pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 72, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] pad Initial from 43 to PLPMTU 1252 client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 57.894874ms client | 0.043 DEBUG Setting timeout of 57.894874ms client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] pn=0 type=Handshake pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 779 client | -> RX Crypto { offset: 0, len: 739 } client | 0.043 DEBUG [Agent 0x557e033f6500] state -> AuthenticationPending client | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 511, tv_nsec: 852434598 } client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] pn=0 type=Handshake pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 82, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG [Client f446104ad5025cb715904f1c8d] Drop packet number space in client | 0.043 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 99.55172ms client | 0.044 DEBUG Setting timeout of 99.55172ms client | 0.044 DEBUG StateChange(Handshaking) client | 0.044 WARN Cannot create stream ConnectionState client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] Authenticated Ok client | 0.044 DEBUG Write secret available for ApplicationData: SymKey [32]: 88ad1deddb7e2c8c8424f4255386711ebe931850cc712b0ca0df056a133a0a01 client | 0.044 DEBUG Read secret available for ApplicationData: SymKey [32]: 4b75834e8de7ed46cb9dfce01517f6b7e44f47e0096c1aa71765be671c4c1c90 client | 0.044 DEBUG [Agent 0x557e033f6500] SSL_AuthCertificateComplete: Ok(()) client | 0.044 DEBUG [Agent 0x557e033f6500] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] TLS connection complete client | 0.044 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.044 DEBUG [Crypto] Application write key installed client | 0.044 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.044 DEBUG [Crypto] application read keys installed client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] State change from Handshaking -> Connected client | 0.044 INFO [Client f446104ad5025cb715904f1c8d] Connection established client | 0.044 DEBUG stream BiDi creatable client | 0.044 INFO Created stream 0 for https://server4/ziwpgrtihw client | 0.044 INFO Saving https://server4/ziwpgrtihw to "/downloads/ziwpgrtihw" client | 0.044 DEBUG stream UniDi creatable client | 0.044 DEBUG StateChange(Connected) client | 0.044 DEBUG stream 0 writable client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.044 DEBUG CRYPTO for hs offset=0, len=36 client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] pn=1 type=Handshake pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 75 client | TX -> Crypto { offset: 0, len: 36 } client | 0.044 DEBUG packet_sent this=0x557e03409ad0, pn=1, ps=75 client | 0.044 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] pn=0 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, NotEct) len 130 client | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 9785, ignore_order: false } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.044 DEBUG packet_sent this=0x557e03409ad0, pn=0, ps=55 client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [10]: f455326c54256350e714) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 99.528617ms client | 0.044 DEBUG Setting timeout of 99.528617ms server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] pn=22 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 43 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 72, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] Rx ACK space=in, ranges=[8..=9] server | 1.030 DEBUG [recovery::Loss] ACK for Initial - largest_acked=9 server | 1.030 DEBUG on_packets_acked this=0x560de21946d0, limited=1, bytes_in_flight=779, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.030 DEBUG Acked crypto frame space=in offset=0 length=1178 server | 1.030 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:57267] Path validated Instant { tv_sec: 521, tv_nsec: 868560400 } server | 1.030 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 2 server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 1.030 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 1.030 DEBUG Building Short dcid Some(CID [0]: ) server | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 68.3781ms server | 1.030 DEBUG Setting timeout of 68.3781ms server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] Drop packet number space in server | 1.030 DEBUG [recovery::Loss] Reset loss recovery state for Initial server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 42 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 82, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] Rx ACK space=hs, ranges=[0..=0] server | 1.030 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=0 server | 1.030 DEBUG on_packets_acked this=0x560de21946d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=779 server | 1.030 DEBUG Acked crypto frame space=hs offset=0 length=739 server | 1.030 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:57267] Path validated Instant { tv_sec: 521, tv_nsec: 868655348 } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 1.030 DEBUG Building Short dcid Some(CID [0]: ) server | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 51.29544ms server | 1.030 DEBUG Setting timeout of 51.29544ms server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 1.030 DEBUG Building Short dcid Some(CID [0]: ) server | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.030 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 51.216904ms server | 1.030 DEBUG Setting timeout of 51.216904ms server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 75 server | -> RX Crypto { offset: 0, len: 36 } server | 1.031 DEBUG [Agent 0x560de2194650] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] TLS connection complete server | 1.031 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:57267] Path validated Instant { tv_sec: 521, tv_nsec: 869022513 } server | 1.031 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.031 DEBUG [Crypto] application read keys installed server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] State change from Handshaking -> Connected server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] State change from Connected -> Confirmed server | 1.031 DEBUG PMTUD started with probe size 1380 server | 1.031 INFO [Server f446104ad5025cb715904f1c8d] Connection established server | 1.031 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 869022513 } server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, NotEct) len 55 server | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 9785, ignore_order: false } server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 1.031 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 878807513 } server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.031 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f455326c54256350e714) server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 41 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] Drop packet number space hs server | 1.031 DEBUG [recovery::Loss] Reset loss recovery state for Handshake server | 1.031 DEBUG Building Short dcid Some(CID [0]: ) server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [158, 63, 176, 214, 237, 55, 150, 246, 239, 170], stateless_reset_token: [245, 252, 198, 35, 79, 229, 94, 204, 109, 128, 131, 19, 105, 186, 252, 41] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [68, 27, 14, 43, 195, 79, 82, 70, 57, 190], stateless_reset_token: [24, 144, 1, 122, 218, 7, 94, 121, 151, 247, 118, 48, 70, 95, 50, 174] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [49, 27, 115, 69, 110, 252, 46, 168, 184, 166], stateless_reset_token: [63, 247, 247, 50, 101, 68, 159, 11, 184, 85, 92, 240, 249, 3, 101, 221] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [178, 12, 116, 244, 190, 60, 143, 119, 61, 138], stateless_reset_token: [74, 208, 40, 40, 142, 9, 38, 220, 209, 133, 161, 8, 71, 152, 191, 208] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [228, 139, 15, 253, 248, 159, 218, 223, 157, 155], stateless_reset_token: [7, 66, 8, 81, 149, 122, 77, 31, 144, 23, 128, 48, 193, 166, 27, 119] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [140, 213, 255, 20, 79, 234, 214, 12, 71, 0], stateless_reset_token: [29, 143, 211, 97, 216, 85, 101, 50, 124, 225, 195, 8, 10, 119, 59, 102] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [120, 179, 203, 133, 96, 164, 234, 36, 35, 53], stateless_reset_token: [204, 154, 240, 100, 38, 185, 75, 154, 96, 203, 191, 44, 203, 12, 225, 255] } server | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 8550, ignore_order: false } server | TX -> Padding { len: 1055 } server | 1.031 DEBUG packet_sent this=0x560de21946d0, pn=0, ps=1291 server | 1.031 DEBUG ECN probing: sent 1 probes server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.031 DEBUG Building Short dcid Some(CID [0]: ) server | 1.031 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1313 } server | 1.031 DEBUG packet_sent this=0x560de21946d0, pn=1, ps=1332 server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.031 DEBUG Building Short dcid Some(CID [0]: ) server | 1.031 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.031 DEBUG ECN probing: sent 2 probes server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.031 DEBUG Building Short dcid Some(CID [0]: ) server | 1.031 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.031 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 1.416989ms server | 1.031 DEBUG Setting timeout of 1.416989ms server | 1.032 DEBUG [Server f446104ad5025cb715904f1c8d] send session ticket 4069000df446104ad5025cb715904f1c8d0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0af455326c54256350e714110c000000015a5a7a7a000000016ab200c0000000ff02de1a0243e8200244b0686921 server | 1.032 DEBUG Path = 'ziwpgrtihw' server | 1.032 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [0]: ) server | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 451.952µs server | 1.032 DEBUG Setting timeout of 451.952µs server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG CRYPTO for ap offset=0, len=182 server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true } server | TX -> Crypto { offset: 0, len: 182 } server | 1.034 DEBUG packet_sent this=0x560de21946d0, pn=2, ps=1232 server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG CRYPTO for ap offset=182, len=139 server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 207 server | TX -> Crypto { offset: 182, len: 139 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 177, 186, 102, 113, 91, 140, 199, 37, 137, 203, 9, 81, 53, 74, 208, 6, 58, 103, 177, 2, 181, 207, 246, 45, 28, 57, 255, 20, 251, 69, 195, 187, 200, 130, 216, 135] } server | 1.034 DEBUG packet_sent this=0x560de21946d0, pn=3, ps=207 server | 1.034 DEBUG ECN probing: sent 4 probes server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 6.104229ms server | 1.034 DEBUG Setting timeout of 6.104229ms server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 6.081397ms server | 1.034 DEBUG Setting timeout of 6.081397ms server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [0]: ) server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 24 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 1349, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.042 DEBUG ECN probing: sent 5 probes server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [0]: ) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 98.293762ms server | 1.042 DEBUG Setting timeout of 98.293762ms server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [0]: ) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 98.270408ms server | 1.042 DEBUG Setting timeout of 98.270408ms client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] pn=1 type=Handshake pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 41 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] Rx ACK space=hs, ranges=[0..=1] client | 0.076 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=1 client | 0.076 DEBUG on_packets_acked this=0x557e03409ad0, limited=1, bytes_in_flight=55, cwnd=12520, state=SlowStart, new_acked=75 client | 0.076 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] pn=0 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 1291 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [158, 63, 176, 214, 237, 55, 150, 246, 239, 170], stateless_reset_token: [245, 252, 198, 35, 79, 229, 94, 204, 109, 128, 131, 19, 105, 186, 252, 41] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [68, 27, 14, 43, 195, 79, 82, 70, 57, 190], stateless_reset_token: [24, 144, 1, 122, 218, 7, 94, 121, 151, 247, 118, 48, 70, 95, 50, 174] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [49, 27, 115, 69, 110, 252, 46, 168, 184, 166], stateless_reset_token: [63, 247, 247, 50, 101, 68, 159, 11, 184, 85, 92, 240, 249, 3, 101, 221] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [178, 12, 116, 244, 190, 60, 143, 119, 61, 138], stateless_reset_token: [74, 208, 40, 40, 142, 9, 38, 220, 209, 133, 161, 8, 71, 152, 191, 208] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [228, 139, 15, 253, 248, 159, 218, 223, 157, 155], stateless_reset_token: [7, 66, 8, 81, 149, 122, 77, 31, 144, 23, 128, 48, 193, 166, 27, 119] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [140, 213, 255, 20, 79, 234, 214, 12, 71, 0], stateless_reset_token: [29, 143, 211, 97, 216, 85, 101, 50, 124, 225, 195, 8, 10, 119, 59, 102] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [120, 179, 203, 133, 96, 164, 234, 36, 35, 53], stateless_reset_token: [204, 154, 240, 100, 38, 185, 75, 154, 96, 203, 191, 44, 203, 12, 225, 255] } client | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 8550, ignore_order: false } client | -> RX Padding { len: 1055 } client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] State change from Connected -> Confirmed client | 0.076 DEBUG PMTUD started with probe size 1380 client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] Drop packet number space hs client | 0.076 DEBUG [recovery::Loss] Reset loss recovery state for Handshake client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] No preferred address to migrate to client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 511, tv_nsec: 894446607 } client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.076 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] pn=1 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1323 } client | 0.076 DEBUG packet_sent this=0x557e03409ad0, pn=1, ps=1352 client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG ECN probing: sent 1 probes client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 8.319761ms client | 0.076 DEBUG Setting timeout of 8.319761ms client | 0.076 WARN Unhandled event StateChange(Confirmed) client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 8.292941ms client | 0.077 DEBUG Setting timeout of 8.292941ms client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] pn=1 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 1332 client | -> RX Ping client | -> RX Padding { len: 1313 } client | 0.077 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 886968501 } client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 511, tv_nsec: 886968501 } client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] pn=2 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 36 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 7, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 0.077 DEBUG ECN probing: sent 2 probes client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 109.381327ms client | 0.077 DEBUG Setting timeout of 109.381327ms client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 109.349948ms client | 0.077 DEBUG Setting timeout of 109.349948ms client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] pn=2 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 1232 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | -> RX Crypto { offset: 0, len: 182 } client | 0.079 DEBUG [Agent 0x557e033f6500] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.079 DEBUG setting max_stream_data to 1048576 client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 511, tv_nsec: 897387591 } client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 8.505015ms client | 0.079 DEBUG Setting timeout of 8.505015ms client | 0.079 DEBUG stream BiDi creatable client | 0.079 DEBUG stream UniDi creatable client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] delay duration 8.458068ms client | 0.079 DEBUG Setting timeout of 8.458068ms client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 220313111 } } client | 0.079 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 220313111 } }) client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.079 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 888954981 } client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] pn=3 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 14, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.079 DEBUG ECN probing: sent 3 probes client | 0.079 DEBUG Setting timeout of 331.285464ms client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.079 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 889138824 } client | 0.079 DEBUG [Client f446104ad5025cb715904f1c8d] pn=4 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 37, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.080 DEBUG ECN probing: sent 4 probes client | 0.080 DEBUG Setting timeout of 331.110368ms client | 0.080 DEBUG Setting timeout of 331.099978ms client | 0.085 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.085 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 895067741 } client | 0.085 DEBUG [Client f446104ad5025cb715904f1c8d] pn=5 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 778, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.085 DEBUG ECN probing: sent 5 probes client | 0.085 DEBUG Setting timeout of 325.163317ms client | 0.085 DEBUG Setting timeout of 325.150954ms server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 1352 server | -> RX Ping server | -> RX Padding { len: 1323 } server | 1.064 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 521, tv_nsec: 902351283 } server | 1.064 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 521, tv_nsec: 902351283 } server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 26 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 1.064 DEBUG ECN probing: sent 6 probes server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 75.751141ms server | 1.064 DEBUG Setting timeout of 75.751141ms server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 36 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 7, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] Rx ACK space=ap, ranges=[0..=1] server | 1.064 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1 server | 1.064 DEBUG on_packets_acked this=0x560de21946d0, limited=1, bytes_in_flight=1439, cwnd=12320, state=SlowStart, new_acked=2623 server | 1.064 DEBUG PMTUD probe of size 1380 succeeded server | 1.064 DEBUG PMTUD started with probe size 1420 server | 1.064 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1353 } server | 1.064 DEBUG packet_sent this=0x560de21946d0, pn=6, ps=1372 server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG ECN probing: sent 7 probes server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 82.227658ms server | 1.064 DEBUG Setting timeout of 82.227658ms server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [0]: ) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server f446104ad5025cb715904f1c8d] delay duration 82.208743ms server | 1.064 DEBUG Setting timeout of 82.208743ms server | 1.066 DEBUG [Server f446104ad5025cb715904f1c8d] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 47 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 14, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } server | 1.066 DEBUG [Server f446104ad5025cb715904f1c8d] Rx ACK space=ap, ranges=[0..=2] server | 1.066 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=2 server | 1.066 DEBUG on_packets_acked this=0x560de21946d0, limited=1, bytes_in_flight=1579, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.066 DEBUG Acked crypto frame space=ap offset=0 length=182 server | 1.066 INFO [Server f446104ad5025cb715904f1c8d] ConnectionClose received. Error code: Application(0) frame type 0 reason kthxbye! server | 1.066 DEBUG [Server f446104ad5025cb715904f1c8d] State change from Confirmed -> Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } } server | 1.066 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:57267] Path validated Instant { tv_sec: 521, tv_nsec: 904181908 } server | 1.066 DEBUG [Server f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG Building Short dcid Some(CID [0]: ) server | 1.066 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 521, tv_nsec: 904181908 } server | 1.066 DEBUG [Server f446104ad5025cb715904f1c8d] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:57267 Tos(Cs0, Ect0) len 30 server | TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.066 DEBUG ECN probing: sent 8 probes server | 1.066 DEBUG Setting timeout of 223.62241ms server | 1.066 DEBUG Setting timeout of 223.611379ms server | 1.066 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } }; Total: 3 server | 1.066 DEBUG Setting timeout of 223.508086ms server | 1.066 DEBUG Setting timeout of 223.490954ms server | 1.072 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } }; Total: 4 server | 1.072 DEBUG Setting timeout of 217.562407ms server | 1.072 DEBUG Setting timeout of 217.547299ms client | 0.108 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.108 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.108 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 917630580 } client | 0.108 DEBUG [Client f446104ad5025cb715904f1c8d] pn=6 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3599, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.108 DEBUG ECN probing: sent 6 probes client | 0.108 DEBUG Setting timeout of 302.608482ms client | 0.108 DEBUG Setting timeout of 302.601419ms client | 0.109 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.109 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 918937757 } client | 0.109 DEBUG [Client f446104ad5025cb715904f1c8d] pn=7 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3762, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.109 DEBUG ECN probing: sent 7 probes client | 0.109 DEBUG Setting timeout of 301.31439ms client | 0.109 DEBUG Setting timeout of 301.283643ms client | 0.110 DEBUG [Client f446104ad5025cb715904f1c8d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.110 DEBUG Building Short dcid Some(CID [10]: f455326c54256350e714) client | 0.110 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 511, tv_nsec: 919476235 } client | 0.110 DEBUG [Client f446104ad5025cb715904f1c8d] pn=8 type=Short pri-path:f455326c54256350e714 0.0.0.0:57267->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3829, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.110 DEBUG ECN probing: sent 8 probes client | 0.110 DEBUG Setting timeout of 300.782505ms client | 0.110 DEBUG Setting timeout of 300.772686ms server | 1.095 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } }; Total: 5 server | 1.095 DEBUG Setting timeout of 194.972768ms server | 1.095 DEBUG Setting timeout of 194.954033ms server | 1.096 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } }; Total: 6 server | 1.096 DEBUG Setting timeout of 193.698162ms server | 1.096 DEBUG Setting timeout of 193.684597ms server | 1.096 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } }; Total: 7 server | 1.096 DEBUG Setting timeout of 193.187366ms server | 1.096 DEBUG Setting timeout of 193.175193ms server | 1.291 DEBUG [Server f446104ad5025cb715904f1c8d] State change from Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 522, tv_nsec: 127903344 } } -> Closed(Transport(PeerApplication(0))) server | 1.291 INFO Closing timer expired client | 0.412 DEBUG [Client f446104ad5025cb715904f1c8d] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 220313111 } } -> Closed(Application(0)) client | 0.412 INFO Closing timer expired client | 0.412 DEBUG Output::None client | 0.412 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.412 DEBUG Timer fired while closed client | 0.412 DEBUG Output::None 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-09-11 19:45:18,984 Using the client's key log file. 2025-09-11 19:45:18,995 2025-09-11 19:45:18,995 Using the client's key log file. 2025-09-11 19:45:18,995 Using the client's key log file. 2025-09-11 19:45:19,005 2025-09-11 19:45:19,006 Using the client's key log file. 2025-09-11 19:45:19,213 Check of downloaded files succeeded. 2025-09-11 19:45:19,644 Using the client's key log file. 2025-09-11 19:45:19,851 Check of downloaded files succeeded. 2025-09-11 19:45:20,492 ECN.NONE 5 2025-09-11 19:45:20,492 ECN.ECT1 0 2025-09-11 19:45:20,492 ECN.ECT0 8 2025-09-11 19:45:20,492 ECN.CE 0 2025-09-11 19:45:20,715 ECN.NONE 3 2025-09-11 19:45:20,715 ECN.ECT1 0 2025-09-11 19:45:20,715 ECN.ECT0 8 2025-09-11 19:45:20,715 ECN.CE 0