2025-04-30 08:42:22,690 Generated random file: algfehjvgy of size: 1024 2025-04-30 08:42:22,690 Requests: https://server4:443/algfehjvgy 2025-04-30 08:42:22,749 2025-04-30 08:42:22,749 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_j7hemv1v/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_o3gufetz/ DOWNLOADS=/tmp/download_uw4vibw6/ SERVER_LOGS=/tmp/logs_server_ia4n6znr CLIENT_LOGS=/tmp/logs_client_yp2n4p8d SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/facebook/proxygen/mvfst-interop:latest REQUESTS="https://server4:443/algfehjvgy" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:42:47,464 Container sim Recreate Container sim Recreated Container server Recreate Container client Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | + set -o nounset server | + VERSION=1 server | + HQ_CLI=/proxygen/_build/proxygen/bin/hq server | + PORT=443 server | + LOGLEVEL=2 server | + /setup.sh server | Setting up routes... client | 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 | 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 | 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 | + PROTOCOL=hq-interop server | + HTTPVERSION=0.9 server | + CONN_FLOW_CONTROL=107374182 server | + STREAM_FLOW_CONTROL=107374182 server | ./run_endpoint.sh: line 28: REQUESTS: unbound variable server | ++ tr ' ' '\n' server | ++ awk -F / '{ print "/" $4 }' client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n handshake ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | ++ paste -sd, server | + INVOCATIONS= server | + EARLYDATA=false server | + PSK_FILE= server | + '[' -n handshake ']' server | + case "${TESTCASE}" in server | + '[' server == client ']' server | + '[' server == server ']' server | + echo 'Running QUIC server on [::]:443' server | Running QUIC server on [::]:443 server | + /proxygen/_build/proxygen/bin/hq --mode=server --cert=/certs/cert.pem --key=/certs/priv.key --conn_flow_control=107374182 --stream_flow_control=107374182 --port=443 --httpversion=0.9 --h2port=443 --static_root=/www --logdir=/logs --qlogger_path=/logs --host=:: --congestion=bbr --pacing=true --v=2 server | + tee /logs/server.log client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | W20250430 08:42:23.394322 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:42:23.394376 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:42:23.394385 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:42:23.394389 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | I20250430 08:42:23.394819 25 HQServer.cpp:283] HQ server started at: [::]:443 sim | server:443 is available after 1.041697669s 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 | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' https://server4:443/algfehjvgy ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test handshake --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/algfehjvgy client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 212992 client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: 0.0.0.0:34129 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=67481c2f301d29a6 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:34129->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443] Path validated Instant { tv_sec: 208, tv_nsec: 724655741 } client | 0.001 DEBUG [Client 67481c2f301d29a6] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x557188529270] state -> InProgress client | 0.002 DEBUG [Client 67481c2f301d29a6] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client 67481c2f301d29a6] pn=0 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x55718853c970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=326 client | 0.002 DEBUG [Client 67481c2f301d29a6] pn=1 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.002 DEBUG [Client 67481c2f301d29a6] pad Initial from 366 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55718853c970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client 67481c2f301d29a6] delay duration 3.884167ms client | 0.002 DEBUG Setting timeout of 3.884167ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client 67481c2f301d29a6] delay duration 3.854412ms client | 0.002 DEBUG Setting timeout of 3.854412ms client | 0.007 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client 67481c2f301d29a6] delay duration 294.82313ms client | 0.007 DEBUG Setting timeout of 294.82313ms client | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.303 DEBUG [Client 67481c2f301d29a6] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.303 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.303 DEBUG [Client 67481c2f301d29a6] Lost: EcnEct0 client | 0.303 DEBUG [Client 67481c2f301d29a6] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.303 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.303 DEBUG [Client 67481c2f301d29a6] Lost: EcnEct0 client | 0.303 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=0, len=1213 client | 0.303 DEBUG [Client 67481c2f301d29a6] pn=2 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.303 DEBUG packet_sent this=0x55718853c970, pn=2, ps=1252 client | 0.303 DEBUG ECN probing: sent 3 probes client | 0.303 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=1213, len=326 client | 0.303 DEBUG [Client 67481c2f301d29a6] pn=3 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.304 DEBUG [Client 67481c2f301d29a6] pad Initial from 366 to PLPMTU 1252 client | 0.304 DEBUG packet_sent this=0x55718853c970, pn=3, ps=1252 client | 0.304 DEBUG ECN probing: sent 4 probes client | 0.304 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.304 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG [Client 67481c2f301d29a6] delay duration 599.90344ms client | 0.304 DEBUG Setting timeout of 599.90344ms client | 0.905 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.905 DEBUG [Client 67481c2f301d29a6] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.905 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.905 DEBUG [Client 67481c2f301d29a6] Lost: EcnEct0 client | 0.905 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 0.905 DEBUG [Client 67481c2f301d29a6] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.905 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.905 DEBUG [Client 67481c2f301d29a6] Lost: EcnEct0 client | 0.905 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=0, len=1213 client | 0.905 DEBUG [Client 67481c2f301d29a6] pn=4 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.905 DEBUG packet_sent this=0x55718853c970, pn=4, ps=1252 client | 0.905 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=1213, len=326 client | 0.905 DEBUG [Client 67481c2f301d29a6] pn=5 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.905 DEBUG [Client 67481c2f301d29a6] pad Initial from 366 to PLPMTU 1252 client | 0.905 DEBUG packet_sent this=0x55718853c970, pn=5, ps=1252 client | 0.905 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [8]: 67481c2f301d29a6) scid Some(CID [0]: ) client | 0.905 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.905 DEBUG [Client 67481c2f301d29a6] delay duration 1.199907457s client | 0.905 DEBUG Setting timeout of 1.199907457s client | 1.510 DEBUG [Client 67481c2f301d29a6] pn=8541491 type=Initial pri-path:67481c2f301d29a6 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 84, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 1094 } client | 1.510 DEBUG Read Ok(90) bytes client | 1.511 DEBUG Write secret available for Handshake: SymKey [32]: ac0fc065a74ff8753f790c76bc49d828ee86b75c9a35eeac45fa0e9492affecf client | 1.511 DEBUG Read secret available for Handshake: SymKey [32]: 9451657c221a40a2c89728492a6812b97939a355b5953fa9c4454629e46320fa client | 1.511 DEBUG [Agent 0x557188529270] state -> InProgress client | 1.511 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.511 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.511 DEBUG [Crypto] Handshake keys installed client | 1.511 DEBUG [Client 67481c2f301d29a6] Rx ACK space=in, ranges=[0..=1] client | 1.511 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 1.511 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] slow start += 2504 client | 1.511 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x55718853c970, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=2504 client | 1.511 DEBUG Acked crypto frame space=in offset=1213 length=326 client | 1.511 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 1.511 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 210, tv_nsec: 234148606 } client | 1.511 DEBUG [Client 67481c2f301d29a6] Changing to use Server CID=4000001dffab6158 client | 1.511 DEBUG [Client 67481c2f301d29a6] State change from WaitInitial -> Handshaking client | 1.511 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG Building Initial dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.511 DEBUG [Client 67481c2f301d29a6] pn=6 type=Initial pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 44 client | TX -> Ack { largest_acknowledged: 8541491, ack_delay: 87, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.511 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.511 DEBUG [Client 67481c2f301d29a6] pad Initial from 44 to PLPMTU 1252 client | 1.511 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG Building Initial dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.511 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.511 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.511 DEBUG [Client 67481c2f301d29a6] delay duration 3.919621728s client | 1.511 DEBUG Setting timeout of 3.919621728s client | 1.511 DEBUG [Client 67481c2f301d29a6] pn=8541491 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 753 client | -> RX Crypto { offset: 0, len: 712 } client | 1.511 DEBUG Read Ok(712) bytes client | 1.512 DEBUG [Agent 0x557188529270] state -> AuthenticationPending client | 1.512 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 210, tv_nsec: 234989097 } client | 1.512 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Initial dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.512 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.512 DEBUG [Client 67481c2f301d29a6] pn=0 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 8541491, ack_delay: 98, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.512 DEBUG [Client 67481c2f301d29a6] Drop packet number space in client | 1.512 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 1.512 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG [Client 67481c2f301d29a6] delay duration 4.525204974s client | 1.512 DEBUG Setting timeout of 4.525204974s client | 1.512 DEBUG StateChange(Handshaking) client | 1.512 WARN Cannot create stream ConnectionState client | 1.512 DEBUG [Client 67481c2f301d29a6] Authenticated Ok client | 1.512 DEBUG Write secret available for ApplicationData: SymKey [32]: 6053d0ed5ab7f0cef8cb26ca7d7bcb25eac57df0e72d13c44aeb00153aae03da client | 1.512 DEBUG Read secret available for ApplicationData: SymKey [32]: d83bdf57eedde2d8b66df4611e9a69e96c0aaac8a20311097a166e8d224a5b62 client | 1.512 DEBUG [Agent 0x557188529270] SSL_AuthCertificateComplete: Ok(()) client | 1.512 DEBUG [Agent 0x557188529270] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 1.512 DEBUG [Client 67481c2f301d29a6] TLS connection complete client | 1.512 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.512 DEBUG [Crypto] Application write key installed client | 1.512 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.512 DEBUG [Crypto] application read keys installed client | 1.512 DEBUG [Client 67481c2f301d29a6] State change from Handshaking -> Connected client | 1.512 INFO [Client 67481c2f301d29a6] Connection established client | 1.512 DEBUG stream BiDi creatable client | 1.512 INFO Created stream 0 for https://server4/algfehjvgy client | 1.512 INFO Saving https://server4/algfehjvgy to "/downloads/algfehjvgy" client | 1.512 DEBUG stream UniDi creatable client | 1.512 DEBUG StateChange(Connected) client | 1.512 DEBUG stream 0 writable client | 1.512 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.512 DEBUG CRYPTO for hs offset=0, len=36 client | 1.512 DEBUG [Client 67481c2f301d29a6] pn=1 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 1.512 DEBUG packet_sent this=0x55718853c970, pn=1, ps=73 client | 1.512 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.512 DEBUG [Client 67481c2f301d29a6] pn=0 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 119 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.512 DEBUG packet_sent this=0x55718853c970, pn=0, ps=46 client | 1.512 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.512 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG [Client 67481c2f301d29a6] delay duration 4.525210404s client | 1.512 DEBUG Setting timeout of 4.525210404s client | 1.621 WARN [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.621 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.621 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.621 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG [Client 67481c2f301d29a6] delay duration 4.416971072s client | 1.621 DEBUG Setting timeout of 4.416971072s client | 1.621 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.621 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.621 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG [Client 67481c2f301d29a6] delay duration 4.416919535s client | 1.621 DEBUG Setting timeout of 4.416919535s client | 1.621 DEBUG [Client 67481c2f301d29a6] pn=8541493 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 753 client | -> RX Crypto { offset: 0, len: 712 } client | 1.621 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 210, tv_nsec: 345098142 } client | 1.621 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.621 DEBUG CRYPTO for hs offset=0, len=36 client | 1.621 DEBUG [Client 67481c2f301d29a6] pn=2 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 83 client | TX -> Ack { largest_acknowledged: 8541493, ack_delay: 8, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 1.621 DEBUG packet_sent this=0x55718853c970, pn=2, ps=83 client | 1.621 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.621 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.621 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.621 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG [Client 67481c2f301d29a6] delay duration 4.525188984s client | 1.621 DEBUG Setting timeout of 4.525188984s client | 1.621 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.621 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.621 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.621 DEBUG [Client 67481c2f301d29a6] delay duration 4.525151574s client | 1.621 DEBUG Setting timeout of 4.525151574s client | 1.836 WARN [Client ...] Dropped received packet: Decryption failure; Total: 2 client | 1.836 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.836 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.836 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.836 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.836 DEBUG [Client 67481c2f301d29a6] delay duration 4.310025856s client | 1.836 DEBUG Setting timeout of 4.310025856s client | 1.836 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.836 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.836 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.836 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.836 DEBUG [Client 67481c2f301d29a6] delay duration 4.309977626s client | 1.836 DEBUG Setting timeout of 4.309977626s client | 1.837 DEBUG [Client 67481c2f301d29a6] pn=8541495 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 753 client | -> RX Crypto { offset: 0, len: 712 } client | 1.837 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 210, tv_nsec: 560910834 } client | 1.837 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.837 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.837 DEBUG CRYPTO for hs offset=0, len=36 client | 1.837 DEBUG [Client 67481c2f301d29a6] pn=3 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 85 client | TX -> Ack { largest_acknowledged: 8541495, ack_delay: 7, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }, AckRange { gap: 0, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 1.837 DEBUG packet_sent this=0x55718853c970, pn=3, ps=85 client | 1.837 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.837 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.837 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.837 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.837 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.837 DEBUG [Client 67481c2f301d29a6] delay duration 4.525169744s client | 1.837 DEBUG Setting timeout of 4.525169744s client | 1.837 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.837 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 1.837 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 1.837 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.837 DEBUG [Client 67481c2f301d29a6] delay duration 4.525084054s client | 1.837 DEBUG Setting timeout of 4.525084054s client | 2.247 WARN [Client ...] Dropped received packet: Decryption failure; Total: 3 client | 2.247 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.247 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 2.247 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 2.247 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.247 DEBUG [Client 67481c2f301d29a6] delay duration 4.115140181s client | 2.247 DEBUG Setting timeout of 4.115140181s client | 2.247 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.247 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 2.247 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 2.247 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.247 DEBUG [Client 67481c2f301d29a6] delay duration 4.115098934s client | 2.247 DEBUG Setting timeout of 4.115098934s client | 2.248 DEBUG [Client 67481c2f301d29a6] pn=8541497 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 753 client | -> RX Crypto { offset: 0, len: 712 } client | 2.248 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 210, tv_nsec: 971601112 } client | 2.248 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.248 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 2.248 DEBUG CRYPTO for hs offset=0, len=36 client | 2.248 DEBUG [Client 67481c2f301d29a6] pn=4 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 87 client | TX -> Ack { largest_acknowledged: 8541497, ack_delay: 6, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }, AckRange { gap: 0, range: 0 }, AckRange { gap: 0, range: 0 }], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 2.248 DEBUG packet_sent this=0x55718853c970, pn=4, ps=87 client | 2.248 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 2.248 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.248 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 2.248 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 2.248 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.248 DEBUG [Client 67481c2f301d29a6] delay duration 4.525184305s client | 2.248 DEBUG Setting timeout of 4.525184305s client | 2.248 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.248 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 2.248 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 2.248 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.248 DEBUG [Client 67481c2f301d29a6] delay duration 4.525157435s client | 2.248 DEBUG Setting timeout of 4.525157435s client | 3.013 DEBUG [Client 67481c2f301d29a6] pn=8541498 type=Handshake pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 38 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 63, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 3.014 DEBUG [Client 67481c2f301d29a6] Rx ACK space=hs, ranges=[0..=1] client | 3.014 DEBUG [LossRecovery] ACK for Handshake - largest_acked=1 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 301/15097 ssthresh 18446744073709551615] slow start += 73 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 301/15097 ssthresh 18446744073709551615] on_packets_acked this=0x55718853c970, limited=0, bytes_in_flight=301, cwnd=15097, state=SlowStart, new_acked=73 client | 3.014 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 3.014 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 3.014 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client 67481c2f301d29a6] delay duration 3.011571066s client | 3.014 DEBUG Setting timeout of 3.011571066s client | 3.014 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [8]: 4000001dffab6158) scid Some(CID [0]: ) client | 3.014 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client 67481c2f301d29a6] delay duration 3.011529659s client | 3.014 DEBUG Setting timeout of 3.011529659s client | 3.014 DEBUG [Client 67481c2f301d29a6] pn=8541491 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 400 client | -> RX Crypto { offset: 0, len: 250 } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 71, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [64, 0, 0, 0, 81, 25, 228, 126], stateless_reset_token: [133, 221, 73, 53, 192, 64, 157, 30, 239, 136, 184, 175, 60, 155, 106, 73] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [64, 0, 0, 3, 217, 147, 108, 178], stateless_reset_token: [144, 220, 9, 132, 237, 67, 123, 9, 234, 189, 77, 241, 51, 234, 57, 164] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [64, 0, 0, 2, 36, 148, 234, 68], stateless_reset_token: [105, 59, 169, 241, 245, 189, 137, 89, 60, 157, 4, 230, 29, 76, 118, 152] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [64, 0, 0, 6, 25, 51, 102, 38], stateless_reset_token: [14, 74, 185, 208, 1, 210, 239, 153, 174, 44, 91, 122, 167, 180, 232, 231] } client | -> RX Padding { len: 6 } client | 3.014 DEBUG Read Ok(250) bytes client | 3.014 DEBUG [0x557188529270] Got resumption token [921]: 02000633fae59d8e..df7d3c5bb0819706 client | 3.014 DEBUG [Agent 0x557188529270] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 3.014 DEBUG setting max_stream_data to 107374182 client | 3.014 DEBUG [Client 67481c2f301d29a6] Rx ACK space=ap, ranges=[0..=0] client | 3.014 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 255/15143 ssthresh 18446744073709551615] slow start += 46 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 255/15143 ssthresh 18446744073709551615] on_packets_acked this=0x55718853c970, limited=0, bytes_in_flight=255, cwnd=15143, state=SlowStart, new_acked=46 client | 3.014 DEBUG [Client 67481c2f301d29a6] State change from Connected -> Confirmed client | 3.014 DEBUG PMTUD started with probe size 1380 client | 3.014 DEBUG [Client 67481c2f301d29a6] Drop packet number space hs client | 3.014 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 3.014 DEBUG [Client 67481c2f301d29a6] No preferred address to migrate to client | 3.014 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 211, tv_nsec: 737751763 } client | 3.014 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.014 DEBUG Sending PMTUD probe of size 1380, count 1 client | 3.014 DEBUG [Client 67481c2f301d29a6] pn=1 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ack { largest_acknowledged: 8541491, ack_delay: 41, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Ping client | TX -> Padding { len: 1317 } client | 3.014 DEBUG packet_sent this=0x55718853c970, pn=1, ps=1352 client | 3.014 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client 67481c2f301d29a6] delay duration 3.240238091s client | 3.014 DEBUG Setting timeout of 3.240238091s client | 3.014 DEBUG stream BiDi creatable client | 3.014 DEBUG stream UniDi creatable client | 3.014 DEBUG stream 0 complete client | 3.014 WARN Unhandled event StateChange(Confirmed) client | 3.014 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client 67481c2f301d29a6] delay duration 3.240203827s client | 3.014 DEBUG Setting timeout of 3.240203827s client | 3.015 DEBUG [Client 67481c2f301d29a6] pn=8541492 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 1072 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | -> RX Padding { len: 23 } client | 3.015 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 211, tv_nsec: 758601512 } client | 3.015 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.015 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG [Client 67481c2f301d29a6] delay duration 19.967029ms client | 3.015 DEBUG Setting timeout of 19.967029ms client | 3.015 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.015 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG [Client 67481c2f301d29a6] delay duration 19.925471ms client | 3.015 DEBUG Setting timeout of 19.925471ms client | 3.015 DEBUG [Client 67481c2f301d29a6] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 221, tv_nsec: 459668958 } } client | 3.015 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 221, tv_nsec: 459668958 } }) client | 3.015 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.015 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 211, tv_nsec: 738707550 } client | 3.015 DEBUG [Client 67481c2f301d29a6] pn=2 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 8541492, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.015 DEBUG Setting timeout of 9.720881539s client | 3.122 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.122 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.122 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 211, tv_nsec: 846038206 } client | 3.122 DEBUG [Client 67481c2f301d29a6] pn=3 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 8541492, ack_delay: 13429, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.122 DEBUG Setting timeout of 9.6135282s client | 3.122 DEBUG Setting timeout of 9.613516128s client | 3.338 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.338 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.338 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 212, tv_nsec: 62034058 } client | 3.338 DEBUG [Client 67481c2f301d29a6] pn=4 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 8541492, ack_delay: 40429, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.338 DEBUG Setting timeout of 9.397499727s client | 3.338 DEBUG Setting timeout of 9.397484288s client | 3.749 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.749 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 3.749 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 212, tv_nsec: 472682005 } client | 3.749 DEBUG [Client 67481c2f301d29a6] pn=5 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 8541492, ack_delay: 91760, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.749 DEBUG Setting timeout of 8.986845198s client | 3.749 DEBUG Setting timeout of 8.986827775s server | I20250430 08:42:28.164438 32 H1QDownstreamSession.h:84] onConnectionEnd client | 4.516 DEBUG [Client 67481c2f301d29a6] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.516 DEBUG Building Short dcid Some(CID [8]: 4000001dffab6158) client | 4.516 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 213, tv_nsec: 239907340 } client | 4.516 DEBUG [Client 67481c2f301d29a6] pn=6 type=Short pri-path:4000001dffab6158 0.0.0.0:34129->193.167.100.100:443 IpTos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 8541492, ack_delay: 187663, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.516 DEBUG Setting timeout of 8.219595547s client | 4.516 DEBUG Setting timeout of 8.219579237s client | 12.736 DEBUG [Client 67481c2f301d29a6] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 221, tv_nsec: 459668958 } } -> Closed(Application(0)) client | 12.736 INFO Closing timer expired client | 12.736 DEBUG Output::None client | 12.736 WARN Unhandled event StateChange(Closed(Application(0))) client | 12.736 DEBUG Timer fired while closed client | 12.736 DEBUG Output::None client exited with code 0 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:42:47,557 Using the client's key log file. 2025-04-30 08:42:47,566 2025-04-30 08:42:47,567 Using the client's key log file. 2025-04-30 08:42:47,567 Using the client's key log file. 2025-04-30 08:42:47,575 2025-04-30 08:42:47,576 Using the client's key log file. 2025-04-30 08:42:47,862 Check of downloaded files succeeded. 2025-04-30 08:42:49,043 Check of downloaded files succeeded.