2025-04-30 09:37:58,916 Generated random file: tpjervgoew of size: 5120 2025-04-30 09:37:58,916 Generated random file: mkpkunzpwv of size: 10240 2025-04-30 09:37:58,916 Requests: https://server4:443/tpjervgoew https://server4:443/mkpkunzpwv 2025-04-30 09:37:58,974 2025-04-30 09:37:58,975 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_lc1bgn3_/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_hrqz5_rk/ DOWNLOADS=/tmp/download_9mbfrndj/ SERVER_LOGS=/tmp/logs_server_61j60_ds CLIENT_LOGS=/tmp/logs_client_5o_19u6z SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=martenseemann/quic-go-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/tpjervgoew https://server4:443/mkpkunzpwv" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 09:38:11,034 Container sim Created Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 client | Setting up routes... client | Actual changes: 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 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 server | Endpoint's IPv4 address is 193.167.100.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 resumption ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp client | Using commit: e4bb2dbd5557c9417b30cf9fcd9032fd6fea5366 server | + P12CERT=/tmp/tmp.9Ft6JYelMa server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password client | wait-for-it.sh: waiting 10 seconds for sim:57832 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.9Ft6JYelMa server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.9Ft6JYelMa -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 | 4e:8a:52:ec:6f:cd:91:f4:c0:8b:1f:64:9b:95:fc:6d: server | 78:b9:25:19 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Wed Apr 30 09:37:58 2025 server | Not After : Sat May 10 09:37:58 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:b6:a5:8f:6d:8e:95:18:34:88:cf:7f:8a:1c:7e:24: server | be:fc:71:be:d5:d6:35:28:10:af:03:93:69:d5:70:a3: server | b3:f3:1a:48:a5:43:5b:8a:c5:05:20:d1:d0:5d:59:bd: server | 80:9d:9f:f4:d2:81:48:c1:ee:51:f1:6d:30:60:1b:7d: server | b1 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 | 69:d3:2a:64:84:18:94:72:14:b2:c6:cd:5d:0f:d1:d1: server | 22:60:2d:34 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | ff:8e:e5:6f:ca:64:db:dd:d7:7c:e2:a1:81:b5:4a:68: server | 4c:39:56:8a server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:bd:28:20:30:c8:42:a6:fc:ae:ea:3c: server | 1c:41:d8:21:d9:14:53:78:21:ca:42:19:b4:b4:f2:61: server | 29:e3:12:3c:30:02:21:00:8c:3e:53:f9:8b:4a:94:c8: server | ff:7a:91:ca:0d:95:a3:64:c7:d7:d1:e1:52:4b:b1:9f: server | 86:38:36:74:81:41:72:fc server | Fingerprint (SHA-256): server | 51:DA:E9:BD:FB:3C:97:AB:76:44:AE:0F:BE:6E:29:5F:EC:4A:B3:2A:6F:56:DC:B8:43:21:F3:B5:FE:3B:38:CE server | Fingerprint (SHA1): server | 6E:D0:24:24:09:17:B1:CF:4B:88:1D:F1:F6:BA:8E:98:0F:61:3A:62 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 | + '[' resumption = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test resumption --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.756 DEBUG [Server] Unsupported version: 57414954 server | 0.756 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:38261 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.017031463s server | 0.756 DEBUG [Server] Unsupported version: 57414954 server | 0.756 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:38261 IpTos(Cs0, NotEct) len 15 server | 0.756 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.756 DEBUG [Server] Unsupported version: 57414954 server | 0.756 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:38261 IpTos(Cs0, NotEct) len 15 server | 0.756 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) 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 | Starting QUIC client... client | Client params: client | Test case: resumption server | 0.998 DEBUG [Server] Handle initial server | 0.998 INFO AddressValidation: no token; accepting server | 0.998 INFO [Server] Accept connection CID [19]: bbe389819360fc1699c2c4ee8f66baa78b1b24 server | 0.998 DEBUG Overwrite initial version Version1 ==> Version1 server | 0.999 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 0.999 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [19]: bbe389819360fc1699c2c4ee8f66baa78b1b24 server | 0.999 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=bbe389819360fc1699c2c4ee8f66baa78b1b24 server | 0.999 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 0.999 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 0.999 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] State change from Init -> WaitInitial server | 0.999 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, NotEct) len 1280 server | -> RX Padding { len: 952 } server | -> RX Crypto { offset: 0, len: 277 } server | 0.999 DEBUG Read Ok(277) bytes server | 0.999 DEBUG 0-RTT: no token, no 0-RTT server | 1.000 DEBUG Read secret available for Handshake: SymKey [32]: 13e03e8c203396176d73640d2faa8cbedda57f7a4877383978bd0a49b573c83a server | 1.000 DEBUG Write secret available for Handshake: SymKey [32]: 43a79777bd40ca01d1ac17ff7d39ef217eeb1cdbedf2be5ef7064d3216c26911 server | 1.000 DEBUG Writing transport parameters, msg=8 server | 1.000 DEBUG Read secret available for ApplicationData: SymKey [32]: 0e15c331f86a78552a8ea53b58bf525b9b7ad7ac0f941b87f293fdbd3c80c2b5 server | 1.000 DEBUG Write secret available for ApplicationData: SymKey [32]: 0786569dc633bf7354deb8013e334a0ad0461a161f7525f31c9d48aa72080d52 server | 1.000 DEBUG [Agent 0x5558e15a11d0] state -> InProgress server | 1.000 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.000 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.000 DEBUG [Crypto] Handshake keys installed server | 1.000 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.000 DEBUG [Crypto] Application write key installed server | 1.000 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 882874054 } server | 1.000 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:41679] Make permanent server | 1.000 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:41679] set as primary path server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] State change from WaitInitial -> Handshaking server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.000 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG CRYPTO for in offset=0, len=90 server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 136 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 1.000 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG CRYPTO for hs offset=0, len=736 server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 912 server | TX -> Crypto { offset: 0, len: 736 } server | 1.000 DEBUG packet_sent this=0x5558e15a0b40, pn=0, ps=776 server | 1.000 DEBUG Building Short dcid Some(CID [0]: ) server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pad Initial from 912 to PLPMTU 1232 server | 1.000 DEBUG packet_sent this=0x5558e15a0b40, pn=0, ps=456 server | 1.000 DEBUG ECN probing: sent 1 probes server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.000 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG Building Short dcid Some(CID [0]: ) server | 1.000 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 297.170329ms server | 1.000 DEBUG Setting timeout of 297.170329ms server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.000 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.000 DEBUG Building Short dcid Some(CID [0]: ) server | 1.000 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.000 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 297.136605ms server | 1.000 DEBUG Setting timeout of 297.136605ms server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=1 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, NotEct) len 1204 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Padding { len: 1158 } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Rx ACK space=in, ranges=[0..=0] server | 1.034 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.034 DEBUG on_packets_acked this=0x5558e15a0b40, limited=1, bytes_in_flight=776, cwnd=12320, state=SlowStart, new_acked=456 server | 1.034 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.034 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:41679] Path validated Instant { tv_sec: 337, tv_nsec: 919275907 } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Drop packet number space in server | 1.034 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, NotEct) len 76 server | -> RX Crypto { offset: 0, len: 36 } server | 1.034 DEBUG Read Ok(36) bytes server | 1.034 DEBUG [Agent 0x5558e15a11d0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] TLS connection complete server | 1.034 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:41679] Path validated Instant { tv_sec: 337, tv_nsec: 919275907 } server | 1.034 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.034 DEBUG [Crypto] application read keys installed server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] State change from Handshaking -> Connected server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] State change from Connected -> Confirmed server | 1.034 DEBUG PMTUD started with probe size 1380 server | 1.034 INFO [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Connection established server | 1.034 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 919275907 } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 7b7bc3755a444b7739d6) server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 41 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Drop packet number space hs server | 1.034 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [60, 130, 83, 233, 219, 11, 101, 242, 11, 82], stateless_reset_token: [76, 75, 12, 52, 159, 230, 176, 136, 142, 96, 163, 208, 13, 202, 254, 132] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [68, 232, 99, 120, 69, 183, 197, 98, 79, 51], stateless_reset_token: [51, 147, 241, 49, 43, 216, 36, 252, 230, 210, 105, 12, 147, 185, 125, 170] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [33, 116, 88, 186, 131, 23, 212, 162, 93, 184], stateless_reset_token: [253, 27, 159, 72, 151, 114, 26, 22, 161, 86, 255, 209, 237, 173, 54, 43] } server | TX -> Padding { len: 1182 } server | 1.034 DEBUG packet_sent this=0x5558e15a0b40, pn=0, ps=1291 server | 1.034 DEBUG ECN probing: sent 2 probes server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] 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 Sending PMTUD probe of size 1380, count 1 server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1313 } server | 1.034 DEBUG packet_sent this=0x5558e15a0b40, pn=1, ps=1332 server | 1.034 DEBUG ECN probing: sent 3 probes server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.549454ms server | 1.034 DEBUG Setting timeout of 1.549454ms server | 1.034 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.528755ms server | 1.034 DEBUG Setting timeout of 1.528755ms server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 48 server | -> RX Stream { stream_id: 0, offset: 0, len: >>17, fin: true } server | 1.034 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 939824571 } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG Building Short dcid Some(CID [0]: ) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.506704ms server | 1.034 DEBUG Setting timeout of 1.506704ms server | 1.035 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] send session ticket 406e0013bbe389819360fc1699c2c4ee8f66baa78b1b240104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a7b7bc3755a444b7739d6110c000000010aca4aba000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.035 DEBUG Path = 'tpjervgoew' server | 1.035 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.035 DEBUG Building Short dcid Some(CID [0]: ) server | 1.035 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.035 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 500.071µs server | 1.035 DEBUG Setting timeout of 500.071µs server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.037 DEBUG Building Short dcid Some(CID [0]: ) server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } server | 1.037 DEBUG packet_sent this=0x5558e15a0b40, pn=2, ps=1232 server | 1.037 DEBUG ECN probing: sent 4 probes server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.037 DEBUG Building Short dcid Some(CID [0]: ) server | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.181926ms server | 1.037 DEBUG Setting timeout of 1.181926ms server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.037 DEBUG Building Short dcid Some(CID [0]: ) server | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.037 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.160466ms server | 1.037 DEBUG Setting timeout of 1.160466ms server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.039 DEBUG Building Short dcid Some(CID [0]: ) server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } server | 1.039 DEBUG packet_sent this=0x5558e15a0b40, pn=3, ps=1232 server | 1.039 DEBUG ECN probing: sent 5 probes server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.039 DEBUG Building Short dcid Some(CID [0]: ) server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } server | 1.039 DEBUG packet_sent this=0x5558e15a0b40, pn=4, ps=1232 server | 1.039 DEBUG ECN probing: sent 6 probes server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.039 DEBUG Building Short dcid Some(CID [0]: ) server | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.752475ms server | 1.039 DEBUG Setting timeout of 1.752475ms server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.039 DEBUG Building Short dcid Some(CID [0]: ) server | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.039 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.735042ms server | 1.039 DEBUG Setting timeout of 1.735042ms server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] 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 bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } server | 1.042 DEBUG packet_sent this=0x5558e15a0b40, pn=5, ps=1232 server | 1.042 DEBUG ECN probing: sent 7 probes server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] 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 CRYPTO for ap offset=0, len=321 server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 672 server | TX -> Stream { stream_id: 0, offset: 4842, len: 278, fin: true } server | TX -> Crypto { offset: 0, len: 321 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 32, 81, 44, 196, 206, 169, 121, 116, 172, 56, 222, 124, 79, 151, 25, 90, 75, 221, 81, 242, 230, 103, 177, 63, 77, 11, 57, 55, 112, 224, 99, 158, 9, 225, 130, 85] } server | 1.042 DEBUG packet_sent this=0x5558e15a0b40, pn=6, ps=672 server | 1.042 DEBUG ECN probing: sent 8 probes server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.042 DEBUG Building Short dcid Some(CID [0]: ) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.300056ms server | 1.042 DEBUG Setting timeout of 1.300056ms server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.042 DEBUG Building Short dcid Some(CID [0]: ) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.042 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 1.277924ms server | 1.042 DEBUG Setting timeout of 1.277924ms server | 1.045 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG Building Short dcid Some(CID [0]: ) server | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 9.220576ms server | 1.045 DEBUG Setting timeout of 9.220576ms server | 1.045 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG Building Short dcid Some(CID [0]: ) server | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.045 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 9.20112ms server | 1.045 DEBUG Setting timeout of 9.20112ms server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [0]: ) server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 27 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 2734, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 1.056 DEBUG ECN probing: sent 9 probes server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [0]: ) server | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 120.831198ms server | 1.056 DEBUG Setting timeout of 120.831198ms server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG Building Short dcid Some(CID [0]: ) server | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.056 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 120.807804ms server | 1.056 DEBUG Setting timeout of 120.807804ms server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 39 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 16, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX RetireConnectionId { sequence_number: 0 } server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Rx ACK space=ap, ranges=[0..=0] server | 1.066 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 server | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6932/13611 ssthresh 18446744073709551615] slow start += 1291 server | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6932/13611 ssthresh 18446744073709551615] on_packets_acked this=0x5558e15a0b40, limited=0, bytes_in_flight=6932, cwnd=13611, state=SlowStart, new_acked=1291 server | 1.066 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 971608825 } server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG Building Short dcid Some(CID [0]: ) server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 48 server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [154, 3, 153, 52, 218, 60, 193, 242, 115, 176], stateless_reset_token: [176, 164, 58, 253, 208, 220, 247, 163, 76, 153, 122, 124, 196, 191, 241, 134] } server | 1.066 DEBUG packet_sent this=0x5558e15a0b40, pn=8, ps=48 server | 1.066 DEBUG ECN probing: sent 10 probes server | 1.066 DEBUG ECN probing concluded with 10 probes sent server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG Building Short dcid Some(CID [0]: ) server | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 19.891706ms server | 1.066 DEBUG Setting timeout of 19.891706ms server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG Building Short dcid Some(CID [0]: ) server | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.066 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 19.85049ms server | 1.066 DEBUG Setting timeout of 19.85049ms server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 6, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Rx ACK space=ap, ranges=[0..=2] server | 1.068 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.068 INFO ECN validation succeeded, path is capable server | 1.068 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4416/16175 ssthresh 18446744073709551615] slow start += 2564 server | 1.068 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4416/16175 ssthresh 18446744073709551615] on_packets_acked this=0x5558e15a0b40, limited=0, bytes_in_flight=4416, cwnd=16175, state=SlowStart, new_acked=2564 server | 1.068 DEBUG PMTUD probe of size 1380 succeeded server | 1.068 DEBUG PMTUD started with probe size 1420 server | 1.068 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.068 DEBUG Building Short dcid Some(CID [0]: ) server | 1.068 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1353 } server | 1.068 DEBUG packet_sent this=0x5558e15a0b40, pn=9, ps=1372 server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.068 DEBUG Building Short dcid Some(CID [0]: ) server | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 17.844378ms server | 1.068 DEBUG Setting timeout of 17.844378ms server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.068 DEBUG Building Short dcid Some(CID [0]: ) server | 1.068 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.068 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 17.821525ms server | 1.068 DEBUG Setting timeout of 17.821525ms server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 6, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] Rx ACK space=ap, ranges=[0..=4] server | 1.071 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.071 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3324/18639 ssthresh 18446744073709551615] slow start += 2464 server | 1.071 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3324/18639 ssthresh 18446744073709551615] on_packets_acked this=0x5558e15a0b40, limited=0, bytes_in_flight=3324, cwnd=18639, state=SlowStart, new_acked=2464 server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG Building Short dcid Some(CID [0]: ) server | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 14.951037ms server | 1.071 DEBUG Setting timeout of 14.951037ms server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG Building Short dcid Some(CID [0]: ) server | 1.071 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.071 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] delay duration 14.882859ms server | 1.071 DEBUG Setting timeout of 14.882859ms server | 1.074 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 32 server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" } server | 1.074 INFO [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 1.074 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 338, tv_nsec: 259722634 } } server | 1.074 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.074 DEBUG Building Short dcid Some(CID [0]: ) server | 1.074 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 337, tv_nsec: 959546240 } server | 1.074 DEBUG [Server bbe389819360fc1699c2c4ee8f66baa78b1b24] pn=10 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:41679 IpTos(Cs0, Ect0) len 30 server | TX -> Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.074 DEBUG Setting timeout of 300.089781ms server | 1.074 DEBUG Setting timeout of 300.079812ms server | 1.076 DEBUG [Server] Handle initial server | 1.076 INFO AddressValidation: no token; accepting server | 1.076 INFO [Server] Accept connection CID [9]: e623ea8c931a4ced4d server | 1.076 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.077 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.077 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [9]: e623ea8c931a4ced4d server | 1.077 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=e623ea8c931a4ced4d server | 1.077 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.077 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.077 DEBUG [Server e623ea8c931a4ced4d] State change from Init -> WaitInitial server | 1.077 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 1280 server | -> RX Padding { len: 622 } server | -> RX Crypto { offset: 0, len: 617 } server | 1.077 DEBUG Read Ok(617) bytes server | 1.077 INFO 0-RTT: transport parameters OK, passing to application checker server | 1.077 WARN AllowZeroRtt accepting 0-RTT server | 1.078 DEBUG Read secret available for ZeroRtt: SymKey [32]: 571dcf3738260112cba307a8a4e7e307a65bf0d9922610232739337f0a87b25a server | 1.078 DEBUG Read secret available for Handshake: SymKey [32]: 1d01ee7d6741e90652915e5f069375729487203bff53f8912b599d3da6c6abe4 server | 1.078 DEBUG Write secret available for Handshake: SymKey [32]: da42e01ec4393f933e251c4af17a2c8a1dd651c84568399218ff185a5b6895c0 server | 1.078 DEBUG Writing transport parameters, msg=8 server | 1.078 DEBUG Read secret available for ApplicationData: SymKey [32]: 9d0c1f593813ade5be97fc1daa59eb59dd9dc847e97e3a0484e1e2ab74095e15 server | 1.078 DEBUG Write secret available for ApplicationData: SymKey [32]: 22345aca39bb774ee2f3c09f932cc476004b89e67d8b3bffad0bc979ae10f608 server | 1.078 DEBUG [Agent 0x5558e15ccb20] state -> InProgress server | 1.078 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.078 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.078 DEBUG [Crypto] Handshake keys installed server | 1.078 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.078 DEBUG [Crypto] Application write key installed server | 1.078 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 961441214 } server | 1.078 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:60700] Make permanent server | 1.078 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:60700] set as primary path server | 1.078 DEBUG [Server e623ea8c931a4ced4d] State change from WaitInitial -> Handshaking server | 1.078 DEBUG Making Read ZeroRtt CryptoDxState, v=Version1 cipher=4865 server | 1.078 DEBUG [Server e623ea8c931a4ced4d] Accepted 0-RTT server | 1.078 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.078 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG CRYPTO for in offset=0, len=96 server | 1.078 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 142 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 96 } server | 1.078 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG CRYPTO for hs offset=0, len=181 server | 1.078 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 363 server | TX -> Crypto { offset: 0, len: 181 } server | 1.078 DEBUG packet_sent this=0x5558e14de840, pn=0, ps=221 server | 1.078 DEBUG Building Short dcid Some(CID [0]: ) server | 1.078 DEBUG [Server e623ea8c931a4ced4d] pad Initial from 363 to PLPMTU 1232 server | 1.078 DEBUG packet_sent this=0x5558e14de840, pn=0, ps=1011 server | 1.078 DEBUG ECN probing: sent 1 probes server | 1.078 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.078 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG Building Short dcid Some(CID [0]: ) server | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.078 DEBUG [Server e623ea8c931a4ced4d] delay duration 297.775246ms server | 1.078 DEBUG Setting timeout of 296.056666ms server | 1.078 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.078 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.078 DEBUG Building Short dcid Some(CID [0]: ) server | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.078 DEBUG [Server e623ea8c931a4ced4d] delay duration 297.723638ms server | 1.078 DEBUG Setting timeout of 296.005058ms server | 1.111 DEBUG [Server e623ea8c931a4ced4d] pn=1 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 1204 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Padding { len: 1158 } server | 1.111 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=in, ranges=[0..=0] server | 1.111 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.111 DEBUG on_packets_acked this=0x5558e14de840, limited=1, bytes_in_flight=221, cwnd=12320, state=SlowStart, new_acked=1011 server | 1.111 DEBUG Acked crypto frame space=in offset=0 length=96 server | 1.111 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60700] Path validated Instant { tv_sec: 337, tv_nsec: 996814728 } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] Drop packet number space in server | 1.112 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.112 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 76 server | -> RX Crypto { offset: 0, len: 36 } server | 1.112 DEBUG Read Ok(36) bytes server | 1.112 DEBUG [Agent 0x5558e15ccb20] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.112 DEBUG [Server e623ea8c931a4ced4d] TLS connection complete server | 1.112 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:60700] Path validated Instant { tv_sec: 337, tv_nsec: 996814728 } server | 1.112 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.112 DEBUG [Crypto] application read keys installed server | 1.112 DEBUG [Server e623ea8c931a4ced4d] State change from Handshaking -> Connected server | 1.112 DEBUG [Server e623ea8c931a4ced4d] State change from Connected -> Confirmed server | 1.112 DEBUG PMTUD started with probe size 1380 server | 1.112 INFO [Server e623ea8c931a4ced4d] Connection established server | 1.112 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 337, tv_nsec: 996814728 } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.112 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: f11066396787c8cad166) server | 1.112 DEBUG [Server e623ea8c931a4ced4d] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 41 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] Drop packet number space hs server | 1.112 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [14, 106, 189, 35, 235, 111, 201, 206, 69, 129], stateless_reset_token: [240, 92, 250, 153, 164, 215, 117, 8, 143, 27, 227, 112, 90, 18, 153, 42] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [217, 135, 45, 109, 228, 143, 81, 93, 151, 70], stateless_reset_token: [74, 111, 254, 177, 125, 106, 227, 227, 129, 250, 231, 21, 12, 136, 34, 23] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [68, 195, 91, 158, 115, 97, 230, 146, 47, 197], stateless_reset_token: [242, 206, 39, 196, 242, 211, 103, 196, 213, 89, 180, 26, 228, 177, 134, 170] } server | TX -> Padding { len: 1182 } server | 1.112 DEBUG packet_sent this=0x5558e14de840, pn=0, ps=1291 server | 1.112 DEBUG ECN probing: sent 2 probes server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.112 DEBUG [Server e623ea8c931a4ced4d] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1313 } server | 1.112 DEBUG packet_sent this=0x5558e14de840, pn=1, ps=1332 server | 1.112 DEBUG ECN probing: sent 3 probes server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.45406ms server | 1.112 DEBUG Setting timeout of 1.45406ms server | 1.112 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.428963ms server | 1.112 DEBUG Setting timeout of 1.428963ms server | 1.112 DEBUG [Server e623ea8c931a4ced4d] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 48 server | -> RX Stream { stream_id: 0, offset: 0, len: >>17, fin: true } server | 1.112 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 338, tv_nsec: 17431919 } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.380359ms server | 1.112 DEBUG Setting timeout of 1.380359ms server | 1.112 DEBUG [Server e623ea8c931a4ced4d] send session ticket 40640009e623ea8c931a4ced4d0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0af11066396787c8cad166110c000000015afa2a7a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.112 DEBUG Path = 'mkpkunzpwv' server | 1.112 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG Building Short dcid Some(CID [0]: ) server | 1.112 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.112 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.207675ms server | 1.112 DEBUG Setting timeout of 1.207675ms server | 1.115 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG Building Short dcid Some(CID [0]: ) server | 1.115 DEBUG [Server e623ea8c931a4ced4d] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } server | 1.115 DEBUG packet_sent this=0x5558e14de840, pn=2, ps=1232 server | 1.115 DEBUG ECN probing: sent 4 probes server | 1.115 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.115 DEBUG Building Short dcid Some(CID [0]: ) server | 1.115 DEBUG [Server e623ea8c931a4ced4d] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } server | 1.115 DEBUG packet_sent this=0x5558e14de840, pn=3, ps=1232 server | 1.115 DEBUG ECN probing: sent 5 probes server | 1.115 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.115 DEBUG Building Short dcid Some(CID [0]: ) server | 1.115 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.115 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.512095ms server | 1.115 DEBUG Setting timeout of 1.512095ms server | 1.115 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.116 DEBUG Building Short dcid Some(CID [0]: ) server | 1.116 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.116 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.489623ms server | 1.116 DEBUG Setting timeout of 1.489623ms server | 1.118 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.118 DEBUG Building Short dcid Some(CID [0]: ) server | 1.118 DEBUG [Server e623ea8c931a4ced4d] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } server | 1.118 DEBUG packet_sent this=0x5558e14de840, pn=4, ps=1232 server | 1.118 DEBUG ECN probing: sent 6 probes server | 1.118 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.118 DEBUG Building Short dcid Some(CID [0]: ) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.118 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.074743ms server | 1.118 DEBUG Setting timeout of 1.074743ms server | 1.118 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.118 DEBUG Building Short dcid Some(CID [0]: ) server | 1.118 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.118 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.051769ms server | 1.118 DEBUG Setting timeout of 1.051769ms server | 1.120 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.120 DEBUG Building Short dcid Some(CID [0]: ) server | 1.120 DEBUG [Server e623ea8c931a4ced4d] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } server | 1.120 DEBUG packet_sent this=0x5558e14de840, pn=5, ps=1232 server | 1.120 DEBUG ECN probing: sent 7 probes server | 1.120 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.120 DEBUG Building Short dcid Some(CID [0]: ) server | 1.120 DEBUG [Server e623ea8c931a4ced4d] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 4842, len: >>1210, fin: false } server | 1.120 DEBUG packet_sent this=0x5558e14de840, pn=6, ps=1232 server | 1.120 DEBUG ECN probing: sent 8 probes server | 1.120 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.120 DEBUG Building Short dcid Some(CID [0]: ) server | 1.120 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.120 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.68639ms server | 1.120 DEBUG Setting timeout of 1.68639ms server | 1.120 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.120 DEBUG Building Short dcid Some(CID [0]: ) server | 1.120 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.120 DEBUG [Server e623ea8c931a4ced4d] delay duration 1.662785ms server | 1.120 DEBUG Setting timeout of 1.662785ms server | 1.123 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG Building Short dcid Some(CID [0]: ) server | 1.123 DEBUG [Server e623ea8c931a4ced4d] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 6052, len: >>1210, fin: false } server | 1.123 DEBUG packet_sent this=0x5558e14de840, pn=7, ps=1232 server | 1.123 DEBUG ECN probing: sent 9 probes server | 1.123 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG Building Short dcid Some(CID [0]: ) server | 1.123 DEBUG [Server e623ea8c931a4ced4d] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 7262, len: >>1210, fin: false } server | 1.123 DEBUG packet_sent this=0x5558e14de840, pn=8, ps=1232 server | 1.123 DEBUG ECN probing: sent 10 probes server | 1.123 DEBUG ECN probing concluded with 10 probes sent server | 1.123 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1073, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG Building Short dcid Some(CID [0]: ) server | 1.123 DEBUG [Server e623ea8c931a4ced4d] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 1073 server | TX -> Stream { stream_id: 0, offset: 8472, len: >>1051, fin: false } server | 1.123 DEBUG packet_sent this=0x5558e14de840, pn=9, ps=1073 server | 1.123 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG Building Short dcid Some(CID [0]: ) server | 1.123 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG [Server e623ea8c931a4ced4d] delay duration 8.8106ms server | 1.123 DEBUG Setting timeout of 8.8106ms server | 1.123 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG Building Short dcid Some(CID [0]: ) server | 1.123 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.123 DEBUG [Server e623ea8c931a4ced4d] delay duration 8.788298ms server | 1.123 DEBUG Setting timeout of 8.788298ms server | 1.133 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.133 DEBUG Building Short dcid Some(CID [0]: ) server | 1.133 DEBUG [Server e623ea8c931a4ced4d] pn=10 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 27 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 2662, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 1.133 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.133 DEBUG Building Short dcid Some(CID [0]: ) server | 1.133 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.133 DEBUG [Server e623ea8c931a4ced4d] delay duration 84.149229ms server | 1.133 DEBUG Setting timeout of 84.149229ms server | 1.133 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.133 DEBUG Building Short dcid Some(CID [0]: ) server | 1.133 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.133 DEBUG [Server e623ea8c931a4ced4d] delay duration 84.127448ms server | 1.133 DEBUG Setting timeout of 84.127448ms server | 1.144 DEBUG [Server e623ea8c931a4ced4d] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 39 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 18, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX RetireConnectionId { sequence_number: 0 } server | 1.144 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=0] server | 1.144 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 server | 1.144 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11029/13611 ssthresh 18446744073709551615] slow start += 1291 server | 1.144 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11029/13611 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=11029, cwnd=13611, state=SlowStart, new_acked=1291 server | 1.144 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 338, tv_nsec: 48953592 } server | 1.144 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.144 DEBUG Building Short dcid Some(CID [0]: ) server | 1.144 DEBUG CRYPTO for ap offset=0, len=305 server | 1.144 DEBUG [Server e623ea8c931a4ced4d] pn=11 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 1125 server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [228, 31, 138, 210, 162, 18, 242, 217, 71, 170], stateless_reset_token: [240, 207, 228, 138, 236, 91, 236, 143, 129, 80, 251, 254, 90, 214, 168, 251] } server | TX -> Stream { stream_id: 0, offset: 9523, len: 717, fin: true } server | TX -> Crypto { offset: 0, len: 305 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 141, 101, 120, 151, 190, 63, 254, 135, 181, 192, 8, 79, 118, 199, 126, 61, 78, 147, 239, 26, 101, 173, 84, 110, 87, 220, 139, 218, 93, 116, 67, 108, 202, 160, 53, 41] } server | 1.144 DEBUG packet_sent this=0x5558e14de840, pn=11, ps=1125 server | 1.144 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.144 DEBUG Building Short dcid Some(CID [0]: ) server | 1.144 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.144 DEBUG [Server e623ea8c931a4ced4d] delay duration 19.800555ms server | 1.144 DEBUG Setting timeout of 19.800555ms server | 1.144 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.144 DEBUG Building Short dcid Some(CID [0]: ) server | 1.144 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.144 DEBUG [Server e623ea8c931a4ced4d] delay duration 19.773224ms server | 1.144 DEBUG Setting timeout of 19.773224ms server | 1.147 DEBUG [Server e623ea8c931a4ced4d] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 7, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | 1.147 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=2] server | 1.147 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.147 INFO ECN validation succeeded, path is capable server | 1.147 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9590/16175 ssthresh 18446744073709551615] slow start += 2564 server | 1.147 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9590/16175 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=9590, cwnd=16175, state=SlowStart, new_acked=2564 server | 1.147 DEBUG PMTUD probe of size 1380 succeeded server | 1.147 DEBUG PMTUD started with probe size 1420 server | 1.147 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.147 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.147 DEBUG Building Short dcid Some(CID [0]: ) server | 1.147 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.147 DEBUG [Server e623ea8c931a4ced4d] pn=12 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1353 } server | 1.147 DEBUG packet_sent this=0x5558e14de840, pn=12, ps=1372 server | 1.147 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.147 DEBUG Building Short dcid Some(CID [0]: ) server | 1.147 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.147 DEBUG [Server e623ea8c931a4ced4d] delay duration 16.555503ms server | 1.147 DEBUG Setting timeout of 16.555503ms server | 1.147 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.147 DEBUG Building Short dcid Some(CID [0]: ) server | 1.147 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.147 DEBUG [Server e623ea8c931a4ced4d] delay duration 16.531077ms server | 1.147 DEBUG Setting timeout of 16.531077ms server | 1.149 DEBUG [Server e623ea8c931a4ced4d] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 4, ack_delay: 5, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } server | 1.149 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=4] server | 1.149 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4 server | 1.149 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8498/18639 ssthresh 18446744073709551615] slow start += 2464 server | 1.149 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8498/18639 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=8498, cwnd=18639, state=SlowStart, new_acked=2464 server | 1.149 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.149 DEBUG Building Short dcid Some(CID [0]: ) server | 1.149 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.149 DEBUG [Server e623ea8c931a4ced4d] delay duration 14.412273ms server | 1.149 DEBUG Setting timeout of 14.412273ms server | 1.149 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.149 DEBUG Building Short dcid Some(CID [0]: ) server | 1.149 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.149 DEBUG [Server e623ea8c931a4ced4d] delay duration 14.361507ms server | 1.149 DEBUG Setting timeout of 14.361507ms server | 1.152 DEBUG [Server e623ea8c931a4ced4d] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 6, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } server | 1.152 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=6] server | 1.152 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6 server | 1.152 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6034/21103 ssthresh 18446744073709551615] slow start += 2464 server | 1.152 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6034/21103 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=6034, cwnd=21103, state=SlowStart, new_acked=2464 server | 1.152 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.152 DEBUG Building Short dcid Some(CID [0]: ) server | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.152 DEBUG [Server e623ea8c931a4ced4d] delay duration 11.214659ms server | 1.152 DEBUG Setting timeout of 11.214659ms server | 1.152 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.152 DEBUG Building Short dcid Some(CID [0]: ) server | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.152 DEBUG [Server e623ea8c931a4ced4d] delay duration 11.168573ms server | 1.152 DEBUG Setting timeout of 11.168573ms server | 1.156 DEBUG [Server e623ea8c931a4ced4d] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 5, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } server | 1.156 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=8] server | 1.156 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8 server | 1.156 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3570/23567 ssthresh 18446744073709551615] slow start += 2464 server | 1.156 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3570/23567 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=3570, cwnd=23567, state=SlowStart, new_acked=2464 server | 1.156 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.156 DEBUG Building Short dcid Some(CID [0]: ) server | 1.156 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.156 DEBUG [Server e623ea8c931a4ced4d] delay duration 8.030038ms server | 1.156 DEBUG Setting timeout of 8.030038ms server | 1.156 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.156 DEBUG Building Short dcid Some(CID [0]: ) server | 1.156 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.156 DEBUG [Server e623ea8c931a4ced4d] delay duration 7.982388ms server | 1.156 DEBUG Setting timeout of 7.982388ms server | 1.165 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.165 DEBUG Building Short dcid Some(CID [0]: ) server | 1.165 DEBUG [Server e623ea8c931a4ced4d] pn=13 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 27 server | TX -> Ack { largest_acknowledged: 5, ack_delay: 1140, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } server | 1.165 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.165 DEBUG Building Short dcid Some(CID [0]: ) server | 1.165 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.165 DEBUG [Server e623ea8c931a4ced4d] delay duration 52.813027ms server | 1.165 DEBUG Setting timeout of 52.813027ms server | 1.165 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.165 DEBUG Building Short dcid Some(CID [0]: ) server | 1.165 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.165 DEBUG [Server e623ea8c931a4ced4d] delay duration 52.788721ms server | 1.165 DEBUG Setting timeout of 52.788721ms server | 1.175 DEBUG [Server e623ea8c931a4ced4d] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 37 server | -> RX Ack { largest_acknowledged: 11, ack_delay: 12, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) } server | 1.175 DEBUG [Server e623ea8c931a4ced4d] Rx ACK space=ap, ranges=[0..=11] server | 1.175 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=11 server | 1.175 WARN ECN validation failed, no ECT(0) packets were newly acked server | 1.175 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/25765 ssthresh 18446744073709551615] slow start += 2198 server | 1.175 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1372/25765 ssthresh 18446744073709551615] on_packets_acked this=0x5558e14de840, limited=0, bytes_in_flight=1372, cwnd=25765, state=SlowStart, new_acked=2198 server | 1.175 DEBUG Acked crypto frame space=ap offset=0 length=305 server | 1.175 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.175 DEBUG Building Short dcid Some(CID [0]: ) server | 1.175 DEBUG [Server e623ea8c931a4ced4d] pn=14 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 20 server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | 1.175 DEBUG packet_sent this=0x5558e14de840, pn=14, ps=21 server | 1.175 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.175 DEBUG Building Short dcid Some(CID [0]: ) server | 1.175 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.175 DEBUG [Server e623ea8c931a4ced4d] delay duration 42.091417ms server | 1.175 DEBUG Setting timeout of 42.091417ms server | 1.176 DEBUG [Server e623ea8c931a4ced4d] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, Ect0) len 32 server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" } server | 1.176 INFO [Server e623ea8c931a4ced4d] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 1.176 DEBUG [Server e623ea8c931a4ced4d] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 338, tv_nsec: 299183240 } } server | 1.176 DEBUG [Server e623ea8c931a4ced4d] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.176 DEBUG Building Short dcid Some(CID [0]: ) server | 1.176 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 338, tv_nsec: 60865634 } server | 1.176 DEBUG [Server e623ea8c931a4ced4d] pn=15 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60700 IpTos(Cs0, NotEct) len 30 server | TX -> Ack { largest_acknowledged: 7, ack_delay: 0, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.176 DEBUG Setting timeout of 198.786357ms server | 1.176 DEBUG Setting timeout of 198.779905ms client exited with code 0 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 09:38:11,129 Using the client's key log file. 2025-04-30 09:38:11,138 2025-04-30 09:38:11,139 Using the client's key log file. 2025-04-30 09:38:11,139 Using the client's key log file. 2025-04-30 09:38:11,147 2025-04-30 09:38:11,147 Using the client's key log file. 2025-04-30 09:38:11,147 Using the client's key log file. 2025-04-30 09:38:12,003 Check of downloaded files succeeded.