2025-04-30 08:42:32,334 Generated random file: bcetoqdkuy of size: 1024 2025-04-30 08:42:32,334 Requests: https://server4:443/bcetoqdkuy 2025-04-30 08:42:32,392 2025-04-30 08:42:32,393 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_jk3sehli/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_vwtv2jz0/ DOWNLOADS=/tmp/download_p9pddppl/ SERVER_LOGS=/tmp/logs_server_joiqzk8d CLIENT_LOGS=/tmp/logs_client_02uiwccm SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/aws/s2n-quic/s2n-quic-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/bcetoqdkuy" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:42:58,937 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 handshake ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.JyAghuMeDJ server | + mkdir -p /neqo/db client | x86_64 server | + certutil -N -d sql:/neqo/db --empty-password client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.JyAghuMeDJ server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.JyAghuMeDJ -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 | 3a:8c:ce:9d:2f:9d:32:f4:ae:2c:91:84:1c:5f:d4:da: server | fb:71:81:76 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:42:32 2025 server | Not After : Sat May 10 08:42:32 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:15:22:bd:d4:40:b3:5f:82:a6:56:25:59:dd:84:33: server | ab:e1:e7:28:40:70:82:04:0a:ed:8b:2f:cb:b9:85:75: server | 95:32:36:ba:c4:dd:c5:a4:ae:8e:5a:59:49:8b:8e:db: server | bf:aa:5a:62:a9:49:23:43:92:c9:cc:2f:07:85:cb:28: server | 2c 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 | 96:d7:37:01:f0:16:f6:83:ad:64:84:cd:db:ac:6c:93: server | 37:96:be:6e server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 04:32:58:49:31:79:e4:a1:c7:e7:82:22:f9:25:f6:88: server | c6:3e:90:65 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:44:02:20:04:da:eb:2a:52:d7:01:b1:27:ba:59:cf: server | 40:1c:d9:c8:c3:21:64:74:e2:36:0c:23:4e:6f:bd:4b: server | f0:81:a3:1e:02:20:3a:39:76:81:cd:10:55:8b:42:c8: server | f7:1a:76:5a:f0:94:01:49:0b:46:b8:3d:d4:b1:70:47: server | 37:cc:87:85:8a:d7 server | Fingerprint (SHA-256): server | AD:5A:35:21:43:FD:AD:87:E7:54:D2:11:13:4B:84:FA:25:CD:7D:2E:EA:47:E9:6A:35:49:FF:BB:0C:9F:99:EC server | Fingerprint (SHA1): server | 4A:C5:CD:AB:10:D3:62:11:0A:A2:0C:37:87:C9:43:DC:A6:60:F4:5F 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 | + '[' handshake = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test handshake --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.696 DEBUG [Server] Unsupported version: 57414954 server | 0.696 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:54523 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.011568457s server | 0.697 DEBUG [Server] Unsupported version: 57414954 server | 0.697 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:54523 IpTos(Cs0, NotEct) len 15 server | 0.697 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.697 DEBUG [Server] Unsupported version: 57414954 server | 0.697 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:54523 IpTos(Cs0, NotEct) len 15 server | 0.697 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | connecting to server4 at 193.167.100.100:443 server | 1.754 DEBUG [Server] Handle initial server | 1.754 INFO AddressValidation: no token; accepting server | 1.754 INFO [Server] Accept connection CID [8]: 43c31f843fce87de server | 1.754 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.755 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.755 INFO [Server ...] Received valid Initial packet with scid CID [16]: 45723bebe2507001419629e6d3ffa5af dcid CID [8]: 43c31f843fce87de server | 1.755 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=43c31f843fce87de server | 1.756 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.756 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.756 DEBUG [Server 43c31f843fce87de] State change from Init -> WaitInitial server | 1.756 DEBUG [Server 43c31f843fce87de] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1252 server | -> RX Crypto { offset: 0, len: 287 } server | -> RX Padding { len: 910 } server | 1.756 DEBUG Read Ok(287) bytes server | 1.756 DEBUG 0-RTT: no token, no 0-RTT server | 1.756 DEBUG Read secret available for Handshake: SymKey [32]: 9ff485d4f9a52125355f02c5db24db9f1e96535c10002234d0a7c2f8ec3d436d server | 1.756 DEBUG Write secret available for Handshake: SymKey [32]: 3a1b426d3a0568ac7ee4654ff1bffdb021ff757a490d8c7a7bea65ba76dd407d server | 1.757 DEBUG Writing transport parameters, msg=8 server | 1.757 DEBUG Read secret available for ApplicationData: SymKey [32]: afd1c6f1cffa8e3fc063d7ce9ba4fa0614b21e4bf84690ad235c661578e1cebd server | 1.757 DEBUG Write secret available for ApplicationData: SymKey [32]: 8456b97791f786f5ce2b11ed7763276be1a645f3c1d26e978c87a404ea1a97ce server | 1.757 DEBUG [Agent 0x55e278d001d0] state -> InProgress server | 1.757 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.757 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.757 DEBUG [Crypto] Handshake keys installed server | 1.757 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.757 DEBUG [Crypto] Application write key installed server | 1.757 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 218, tv_nsec: 106564225 } server | 1.757 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:37314] Make permanent server | 1.757 DEBUG [unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314] set as primary path server | 1.757 DEBUG [Server 43c31f843fce87de] State change from WaitInitial -> Handshaking server | 1.757 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.757 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG CRYPTO for in offset=0, len=123 server | 1.757 DEBUG [Server 43c31f843fce87de] pn=0 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 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.757 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG CRYPTO for hs offset=0, len=723 server | 1.757 DEBUG [Server 43c31f843fce87de] pn=0 type=Handshake pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 967 server | TX -> Crypto { offset: 0, len: 723 } server | 1.757 DEBUG packet_sent this=0x55e278cffb40, pn=0, ps=779 server | 1.757 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 1.757 DEBUG [Server 43c31f843fce87de] pad Initial from 967 to PLPMTU 1232 server | 1.757 DEBUG packet_sent this=0x55e278cffb40, pn=0, ps=453 server | 1.757 DEBUG ECN probing: sent 1 probes server | 1.757 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.757 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 1.757 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.757 DEBUG [Server 43c31f843fce87de] delay duration 296.638026ms server | 1.757 DEBUG Setting timeout of 296.638026ms server | 1.757 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.757 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 1.757 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 1.757 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.757 DEBUG [Server 43c31f843fce87de] delay duration 296.60285ms server | 1.757 DEBUG Setting timeout of 296.60285ms server | 2.055 DEBUG [LossRecovery] PTO timer fired for Initial server | 2.055 DEBUG [LossRecovery] PTO timer fired for Handshake server | 2.055 DEBUG [Server 43c31f843fce87de] Lost: Ack(AckToken { space: Initial, ranges: [PacketRange { largest: 0, smallest: 0, ack_needed: true }] }) server | 2.055 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 218, tv_nsec: 106564225 } server | 2.055 DEBUG [Server 43c31f843fce87de] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 123 }) server | 2.055 INFO Lost crypto frame space=in offset=0 length=123 server | 2.055 DEBUG [Server 43c31f843fce87de] Lost: EcnEct0 server | 2.055 DEBUG [Server 43c31f843fce87de] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 723 }) server | 2.055 INFO Lost crypto frame space=hs offset=0 length=723 server | 2.055 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(Initial | Handshake), paced: false } server | 2.055 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG CRYPTO for in offset=0, len=123 server | 2.055 DEBUG [Server 43c31f843fce87de] pn=1 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 191 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 37608, 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 | 2.055 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG CRYPTO for hs offset=0, len=723 server | 2.055 DEBUG [Server 43c31f843fce87de] pn=1 type=Handshake pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 970 server | TX -> Crypto { offset: 0, len: 723 } server | 2.055 DEBUG packet_sent this=0x55e278cffb40, pn=1, ps=779 server | 2.055 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.055 DEBUG [Server 43c31f843fce87de] pad Initial from 970 to PLPMTU 1232 server | 2.055 DEBUG packet_sent this=0x55e278cffb40, pn=1, ps=453 server | 2.055 DEBUG ECN probing: sent 2 probes server | 2.055 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.055 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.055 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.055 DEBUG [Server 43c31f843fce87de] delay duration 599.768216ms server | 2.055 DEBUG Setting timeout of 599.768216ms server | 2.055 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.055 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.055 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.055 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.055 DEBUG [Server 43c31f843fce87de] delay duration 599.731307ms server | 2.055 DEBUG Setting timeout of 599.731307ms client | GET /bcetoqdkuy server | 2.656 DEBUG [LossRecovery] PTO timer fired for Initial server | 2.656 DEBUG [LossRecovery] PTO timer fired for Handshake server | 2.656 DEBUG [Server 43c31f843fce87de] Lost: Ack(AckToken { space: Initial, ranges: [PacketRange { largest: 0, smallest: 0, ack_needed: true }] }) server | 2.656 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 218, tv_nsec: 407434004 } server | 2.656 DEBUG [Server 43c31f843fce87de] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 123 }) server | 2.656 INFO Lost crypto frame space=in offset=0 length=123 server | 2.656 DEBUG [Server 43c31f843fce87de] Lost: EcnEct0 server | 2.656 DEBUG [Server 43c31f843fce87de] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 723 }) server | 2.656 INFO Lost crypto frame space=hs offset=0 length=723 server | 2.656 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(Initial | Handshake), paced: false } server | 2.656 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG CRYPTO for in offset=0, len=123 server | 2.656 DEBUG [Server 43c31f843fce87de] pn=2 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 191 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 112737, 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 | 2.656 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG CRYPTO for hs offset=0, len=723 server | 2.656 DEBUG [Server 43c31f843fce87de] pn=2 type=Handshake pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 970 server | TX -> Crypto { offset: 0, len: 723 } server | 2.656 DEBUG packet_sent this=0x55e278cffb40, pn=2, ps=779 server | 2.656 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.656 DEBUG [Server 43c31f843fce87de] pad Initial from 970 to PLPMTU 1232 server | 2.656 DEBUG packet_sent this=0x55e278cffb40, pn=2, ps=453 server | 2.656 DEBUG ECN probing: sent 3 probes server | 2.656 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.656 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.656 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.656 DEBUG [Server 43c31f843fce87de] delay duration 29.097784807s server | 2.656 DEBUG Setting timeout of 29.097784807s server | 2.656 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.656 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.656 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.656 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 2.656 DEBUG [Server 43c31f843fce87de] delay duration 29.097748509s server | 2.656 DEBUG Setting timeout of 29.097748509s server | 2.748 DEBUG [Server 43c31f843fce87de] pn=2 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1200 server | -> RX Crypto { offset: 0, len: 287 } server | -> RX Padding { len: 858 } server | 2.748 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 219, tv_nsec: 100678831 } server | 2.748 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.748 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG CRYPTO for in offset=0, len=123 server | 2.748 DEBUG [Server 43c31f843fce87de] pn=3 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 190 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | TX -> Crypto { offset: 0, len: 123 } server | 2.748 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG CRYPTO for hs offset=0, len=723 server | 2.748 DEBUG [Server 43c31f843fce87de] pn=3 type=Handshake pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 969 server | TX -> Crypto { offset: 0, len: 723 } server | 2.748 DEBUG packet_sent this=0x55e278cffb40, pn=3, ps=779 server | 2.748 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.748 DEBUG [Server 43c31f843fce87de] pad Initial from 969 to PLPMTU 1232 server | 2.748 DEBUG packet_sent this=0x55e278cffb40, pn=3, ps=453 server | 2.748 DEBUG ECN probing: sent 4 probes server | 2.748 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.748 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.748 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.748 DEBUG [Server 43c31f843fce87de] delay duration 1.199786411s server | 2.748 DEBUG Setting timeout of 1.199786411s server | 2.748 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.748 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.748 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.748 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.748 DEBUG [Server 43c31f843fce87de] delay duration 1.199743391s server | 2.748 DEBUG Setting timeout of 1.199743391s server | 2.749 DEBUG [Server 43c31f843fce87de] pn=4 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1200 server | -> RX Crypto { offset: 0, len: 287 } server | -> RX Padding { len: 858 } server | 2.749 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 219, tv_nsec: 101525764 } server | 2.749 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.749 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG CRYPTO for in offset=0, len=123 server | 2.749 DEBUG [Server 43c31f843fce87de] pn=4 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 192 server | TX -> Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }, AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | TX -> Crypto { offset: 0, len: 123 } server | 2.749 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG CRYPTO for hs offset=0, len=723 server | 2.749 DEBUG [Server 43c31f843fce87de] pn=4 type=Handshake pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 971 server | TX -> Crypto { offset: 0, len: 723 } server | 2.749 DEBUG packet_sent this=0x55e278cffb40, pn=4, ps=779 server | 2.749 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.749 DEBUG [Server 43c31f843fce87de] pad Initial from 971 to PLPMTU 1232 server | 2.749 DEBUG packet_sent this=0x55e278cffb40, pn=4, ps=453 server | 2.749 DEBUG ECN probing: sent 5 probes server | 2.749 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.749 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.749 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.749 DEBUG [Server 43c31f843fce87de] delay duration 1.199887137s server | 2.749 DEBUG Setting timeout of 1.199887137s server | 2.749 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.749 DEBUG Building Initial dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 2.749 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 2.749 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.749 DEBUG [Server 43c31f843fce87de] delay duration 1.199854226s server | 2.749 DEBUG Setting timeout of 1.199854226s server | 3.262 DEBUG [Server 43c31f843fce87de] pn=5 type=Initial pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 72 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 1816, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Padding { len: 10 } server | 3.262 DEBUG [Server 43c31f843fce87de] Rx ACK space=in, ranges=[0..=0] server | 3.263 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 3.263 DEBUG on_packets_acked this=0x55e278cffb40, limited=1, bytes_in_flight=5707, cwnd=12320, state=SlowStart, new_acked=453 server | 3.263 DEBUG Acked crypto frame space=in offset=0 length=123 server | 3.263 DEBUG [pri-unv-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314] Path validated Instant { tv_sec: 219, tv_nsec: 615177581 } server | 3.263 DEBUG [Server 43c31f843fce87de] Drop packet number space in server | 3.263 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 3.263 DEBUG [Server 43c31f843fce87de] pn=0 type=Handshake pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1180 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 1816, 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: 1080 } server | 3.263 DEBUG [Server 43c31f843fce87de] Rx ACK space=hs, ranges=[0..=0] server | 3.263 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 3.263 DEBUG on_packets_acked this=0x55e278cffb40, limited=1, bytes_in_flight=3116, cwnd=12320, state=SlowStart, new_acked=779 server | 3.263 DEBUG Acked crypto frame space=hs offset=0 length=723 server | 3.263 DEBUG Read Ok(36) bytes server | 3.263 DEBUG [Agent 0x55e278d001d0] 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 | 3.263 DEBUG [Server 43c31f843fce87de] TLS connection complete server | 3.263 DEBUG [pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314] Path validated Instant { tv_sec: 219, tv_nsec: 615177581 } server | 3.263 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 3.263 DEBUG [Crypto] application read keys installed server | 3.263 DEBUG [Server 43c31f843fce87de] State change from Handshaking -> Connected server | 3.263 DEBUG [Server 43c31f843fce87de] State change from Connected -> Confirmed server | 3.263 DEBUG PMTUD started with probe size 1380 server | 3.263 INFO [Server 43c31f843fce87de] Connection established server | 3.263 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 219, tv_nsec: 615177581 } server | 3.263 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.263 DEBUG Building Handshake dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) scid Some(CID [10]: dd7e699998feed99688c) server | 3.263 DEBUG [Server 43c31f843fce87de] pn=5 type=Handshake pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 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 | 3.263 DEBUG [Server 43c31f843fce87de] Drop packet number space hs server | 3.263 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 3.263 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.263 DEBUG [Server 43c31f843fce87de] pn=0 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [92, 139, 17, 251, 25, 226, 23, 82, 252, 172], stateless_reset_token: [80, 11, 7, 248, 2, 21, 12, 172, 141, 54, 18, 171, 169, 133, 167, 120] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [179, 47, 18, 23, 113, 88, 47, 227, 12, 241], stateless_reset_token: [71, 5, 66, 202, 91, 231, 59, 225, 93, 52, 199, 16, 165, 148, 115, 97] } server | TX -> Padding { len: 1177 } server | 3.263 DEBUG packet_sent this=0x55e278cffb40, pn=0, ps=1272 server | 3.263 DEBUG ECN probing: sent 6 probes server | 3.263 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.263 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.263 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.263 DEBUG [Server 43c31f843fce87de] delay duration 1.679459ms server | 3.263 DEBUG Setting timeout of 1.679459ms server | 3.263 DEBUG [Server 43c31f843fce87de] pn=0 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 51 server | -> RX Stream { stream_id: 0, offset: 0, len: 0, fin: false } server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 3.263 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 219, tv_nsec: 635958330 } server | 3.263 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.263 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.263 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.263 DEBUG [Server 43c31f843fce87de] delay duration 1.644714ms server | 3.263 DEBUG Setting timeout of 1.644714ms server | 3.264 DEBUG [Server 43c31f843fce87de] send session ticket 4063000843c31f843fce87de0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0add7e699998feed99688c110c000000012a2a5ada000000016ab200c0000000ff02de1a0243e8200100686921 server | 3.264 DEBUG Path = 'bcetoqdkuy' server | 3.264 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.264 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.264 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.264 DEBUG [Server 43c31f843fce87de] delay duration 632.081µs server | 3.264 DEBUG Setting timeout of 632.081µs server | 3.266 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.266 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.266 DEBUG Sending PMTUD probe of size 1380, count 1 server | 3.266 DEBUG CRYPTO for ap offset=0, len=265 server | 3.266 DEBUG [Server 43c31f843fce87de] pn=1 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true } server | TX -> Crypto { offset: 0, len: 265 } server | 3.266 DEBUG packet_sent this=0x55e278cffb40, pn=1, ps=1332 server | 3.266 DEBUG ECN probing: sent 7 probes server | 3.266 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.266 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.266 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.266 DEBUG [Server 43c31f843fce87de] delay duration 16.803966ms server | 3.266 DEBUG Setting timeout of 16.803966ms server | 3.266 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.266 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.266 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.266 DEBUG [Server 43c31f843fce87de] delay duration 16.777777ms server | 3.266 DEBUG Setting timeout of 16.777777ms server | 3.284 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.284 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.284 DEBUG [Server 43c31f843fce87de] pn=2 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 43 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 2542, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 3.284 DEBUG ECN probing: sent 8 probes server | 3.284 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.284 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.284 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.284 DEBUG [Server 43c31f843fce87de] delay duration 59.997306ms server | 3.284 DEBUG Setting timeout of 59.997306ms server | 3.284 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.284 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.284 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.284 DEBUG [Server 43c31f843fce87de] delay duration 59.970707ms server | 3.284 DEBUG Setting timeout of 59.970707ms server | 3.345 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.345 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.345 DEBUG CRYPTO for ap offset=265, len=40 server | 3.345 DEBUG [Server 43c31f843fce87de] pn=3 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 123 server | TX -> Crypto { offset: 265, len: 40 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 36, 201, 153, 234, 245, 148, 230, 247, 159, 143, 192, 10, 101, 97, 119, 248, 244, 183, 118, 227, 198, 9, 91, 22, 141, 58, 79, 151, 29, 37, 113, 43, 24, 68, 74, 73] } server | 3.345 DEBUG packet_sent this=0x55e278cffb40, pn=3, ps=123 server | 3.345 DEBUG ECN probing: sent 9 probes server | 3.345 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.345 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.345 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.345 DEBUG [Server 43c31f843fce87de] delay duration 6.143627ms server | 3.345 DEBUG Setting timeout of 6.143627ms server | 3.345 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.345 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.345 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.345 DEBUG [Server 43c31f843fce87de] delay duration 6.119391ms server | 3.345 DEBUG Setting timeout of 6.119391ms server | 3.352 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.352 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.352 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.352 DEBUG [Server 43c31f843fce87de] delay duration 3.752968345s server | 3.352 DEBUG Setting timeout of 3.752968345s server | 3.352 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.352 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.352 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.352 DEBUG [Server 43c31f843fce87de] delay duration 3.752941435s server | 3.352 DEBUG Setting timeout of 3.752941435s server | 3.558 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 3.558 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.558 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.558 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.558 DEBUG [Server 43c31f843fce87de] delay duration 3.547541071s server | 3.558 DEBUG Setting timeout of 3.547541071s server | 3.558 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.558 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 3.558 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.558 DEBUG [Server 43c31f843fce87de] delay duration 3.547476149s server | 3.558 DEBUG Setting timeout of 3.547476149s client | Request /bcetoqdkuy completed successfully server | 4.159 WARN [Server ...] Dropped received packet: Decryption failure; Total: 2 server | 4.159 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.159 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.159 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.159 DEBUG [Server 43c31f843fce87de] delay duration 2.946519986s server | 4.159 DEBUG Setting timeout of 2.946519986s server | 4.159 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.159 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.159 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.159 DEBUG [Server 43c31f843fce87de] delay duration 2.946455074s server | 4.159 DEBUG Setting timeout of 2.946455074s server | 4.250 WARN [Server ...] Dropped received packet: Decryption failure; Total: 3 server | 4.250 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.250 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.251 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG [Server 43c31f843fce87de] delay duration 2.854640852s server | 4.251 DEBUG Setting timeout of 2.854640852s server | 4.251 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.251 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG [Server 43c31f843fce87de] delay duration 2.854579638s server | 4.251 DEBUG Setting timeout of 2.854579638s server | 4.251 WARN [Server ...] Dropped received packet: Decryption failure; Total: 4 server | 4.251 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.251 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG [Server 43c31f843fce87de] delay duration 2.853975568s server | 4.251 DEBUG Setting timeout of 2.853975568s server | 4.251 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.251 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.251 DEBUG [Server 43c31f843fce87de] delay duration 2.853940653s server | 4.251 DEBUG Setting timeout of 2.853940653s server | 4.768 DEBUG [Server 43c31f843fce87de] pn=1 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 1472 server | -> RX Ping server | -> RX Padding { len: 1443 } server | 4.768 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 221, tv_nsec: 120636774 } server | 4.768 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 221, tv_nsec: 120636774 } server | 4.768 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.768 DEBUG [Server 43c31f843fce87de] pn=4 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) 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 | 4.768 DEBUG ECN probing: sent 10 probes server | 4.768 DEBUG ECN probing concluded with 10 probes sent server | 4.768 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG Building Short dcid Some(CID [16]: 45723bebe2507001419629e6d3ffa5af) server | 4.768 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG [Server 43c31f843fce87de] delay duration 2.337034111s server | 4.768 DEBUG Setting timeout of 2.337034111s server | 4.768 DEBUG [Server 43c31f843fce87de] pn=2 type=Short pri-path:45723bebe2507001419629e6d3ffa5af [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 147 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 121, 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: [174, 31, 179, 125, 70, 249, 2, 19, 142, 144, 40, 114, 160, 49, 121, 242], stateless_reset_token: [215, 129, 236, 64, 184, 113, 86, 38, 72, 137, 62, 194, 105, 252, 69, 232] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 1, connection_id: [49, 253, 43, 161, 214, 195, 33, 8, 178, 141, 201, 217, 238, 172, 206, 212], stateless_reset_token: [172, 40, 234, 52, 67, 170, 232, 26, 133, 79, 80, 173, 164, 117, 150, 80] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 1, connection_id: [83, 144, 76, 104, 25, 135, 224, 90, 98, 123, 33, 133, 79, 149, 238, 56], stateless_reset_token: [188, 48, 180, 169, 30, 75, 77, 101, 228, 136, 193, 53, 97, 81, 218, 244] } server | -> RX RetireConnectionId { sequence_number: 0 } server | 4.768 DEBUG [Server 43c31f843fce87de] Rx ACK space=ap, ranges=[0..=0] server | 4.768 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 server | 4.768 DEBUG on_packets_acked this=0x55e278cffb40, limited=1, bytes_in_flight=1455, cwnd=12320, state=SlowStart, new_acked=1272 server | 4.768 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 221, tv_nsec: 140854682 } server | 4.768 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG Building Short dcid Some(CID [16]: ae1fb37d46f902138e902872a03179f2) server | 4.768 DEBUG [Server 43c31f843fce87de] pn=5 type=Short pri-path:ae1fb37d46f902138e902872a03179f2 [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, NotEct) len 66 server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [245, 200, 96, 91, 181, 48, 200, 244, 91, 21], stateless_reset_token: [169, 13, 78, 159, 118, 133, 69, 200, 100, 30, 109, 51, 71, 236, 170, 143] } server | TX -> RetireConnectionId { sequence_number: 0 } server | 4.768 DEBUG packet_sent this=0x55e278cffb40, pn=5, ps=66 server | 4.768 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG Building Short dcid Some(CID [16]: ae1fb37d46f902138e902872a03179f2) server | 4.768 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG [Server 43c31f843fce87de] delay duration 19.768347ms server | 4.768 DEBUG Setting timeout of 19.768347ms server | 4.768 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG Building Short dcid Some(CID [16]: ae1fb37d46f902138e902872a03179f2) server | 4.768 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.768 DEBUG [Server 43c31f843fce87de] delay duration 19.741367ms server | 4.768 DEBUG Setting timeout of 19.741367ms server | 4.785 DEBUG [Server 43c31f843fce87de] pn=3 type=Short pri-path:ae1fb37d46f902138e902872a03179f2 [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, Ect0) len 47 server | -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" } server | -> RX Padding { len: 15 } server | 4.785 INFO [Server 43c31f843fce87de] ConnectionClose received. Error code: Transport(0) frame type 0 reason server | 4.785 DEBUG [Server 43c31f843fce87de] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 230, tv_nsec: 773446657 } } server | 4.785 DEBUG [Server 43c31f843fce87de] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.785 DEBUG Building Short dcid Some(CID [16]: ae1fb37d46f902138e902872a03179f2) server | 4.785 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 221, tv_nsec: 137797381 } server | 4.785 DEBUG [Server 43c31f843fce87de] pn=6 type=Short pri-path:ae1fb37d46f902138e902872a03179f2 [::]:443->[::ffff:193.167.0.100]:37314 IpTos(Cs0, NotEct) len 46 server | TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" } server | 4.785 DEBUG Setting timeout of 9.635520516s server | 4.785 DEBUG Setting timeout of 9.635505157s server | 6.370 WARN [Server ...] Dropped received packet: State Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 230, tv_nsec: 773446657 } }; Total: 5 server | 6.370 DEBUG Setting timeout of 8.051153421s server | 6.370 DEBUG Setting timeout of 8.051118005s server | 14.422 DEBUG [Server 43c31f843fce87de] State change from Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 230, tv_nsec: 773446657 } } -> Closed(Transport(PeerError(0))) server | 14.422 INFO Closing timer expired client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:42:59,026 Using the client's key log file. 2025-04-30 08:42:59,034 2025-04-30 08:42:59,035 Using the client's key log file. 2025-04-30 08:42:59,035 Using the client's key log file. 2025-04-30 08:42:59,042 2025-04-30 08:42:59,043 Using the client's key log file. 2025-04-30 08:42:59,334 Check of downloaded files succeeded. 2025-04-30 08:43:00,534 Check of downloaded files succeeded.