2025-09-11 21:25:05,867 Generated random file: qxcomfdpuj of size: 1024 2025-09-11 21:25:05,867 Generated random file: fjxvatwsaq of size: 1024 2025-09-11 21:25:05,868 Generated random file: vkujqxzsfk of size: 1024 2025-09-11 21:25:05,868 Generated random file: abpujbluzj of size: 1024 2025-09-11 21:25:05,868 Generated random file: ynhqqwtmzh of size: 1024 2025-09-11 21:25:05,868 Generated random file: qsjypgrqys of size: 1024 2025-09-11 21:25:05,868 Generated random file: tgngsruxic of size: 1024 2025-09-11 21:25:05,868 Generated random file: ysjpftzbvj of size: 1024 2025-09-11 21:25:05,868 Generated random file: nzvgbvqkwu of size: 1024 2025-09-11 21:25:05,868 Generated random file: kitdnmyzvg of size: 1024 2025-09-11 21:25:05,869 Generated random file: tpmqhqgmot of size: 1024 2025-09-11 21:25:05,869 Generated random file: asckymdohp of size: 1024 2025-09-11 21:25:05,869 Generated random file: jfbctrpgvs of size: 1024 2025-09-11 21:25:05,869 Generated random file: kdrezyxfht of size: 1024 2025-09-11 21:25:05,869 Generated random file: bxeehsvjhv of size: 1024 2025-09-11 21:25:05,869 Generated random file: ctoufcznzb of size: 1024 2025-09-11 21:25:05,869 Generated random file: yszmscdjwu of size: 1024 2025-09-11 21:25:05,869 Generated random file: eihctnjkvw of size: 1024 2025-09-11 21:25:05,870 Generated random file: nluydoeexk of size: 1024 2025-09-11 21:25:05,870 Generated random file: yaruhpfpac of size: 1024 2025-09-11 21:25:05,870 Generated random file: pkvfxootya of size: 1024 2025-09-11 21:25:05,870 Generated random file: iavfctnhlm of size: 1024 2025-09-11 21:25:05,870 Generated random file: friyrnljtp of size: 1024 2025-09-11 21:25:05,870 Generated random file: vfzvyuzozm of size: 1024 2025-09-11 21:25:05,870 Generated random file: ydnhzakist of size: 1024 2025-09-11 21:25:05,870 Generated random file: jdjbgeuogk of size: 1024 2025-09-11 21:25:05,870 Generated random file: lbujjdzvjb of size: 1024 2025-09-11 21:25:05,871 Generated random file: arnmltfkvx of size: 1024 2025-09-11 21:25:05,871 Generated random file: zwxrdwvnnb of size: 1024 2025-09-11 21:25:05,871 Generated random file: rcuxlsoiur of size: 1024 2025-09-11 21:25:05,871 Generated random file: ohrmbxpmkl of size: 1024 2025-09-11 21:25:05,871 Generated random file: ogzeowscsg of size: 1024 2025-09-11 21:25:05,871 Generated random file: upgnrimgah of size: 1024 2025-09-11 21:25:05,871 Generated random file: ielqpxfzex of size: 1024 2025-09-11 21:25:05,871 Generated random file: lfanzqfetl of size: 1024 2025-09-11 21:25:05,872 Generated random file: npovlkzidw of size: 1024 2025-09-11 21:25:05,872 Generated random file: xexyyxaxnk of size: 1024 2025-09-11 21:25:05,872 Generated random file: arcvbujkcq of size: 1024 2025-09-11 21:25:05,872 Generated random file: mluoapcmem of size: 1024 2025-09-11 21:25:05,872 Generated random file: foxudzjcjl of size: 1024 2025-09-11 21:25:05,872 Generated random file: gbdwckwjhy of size: 1024 2025-09-11 21:25:05,872 Generated random file: yhvngkllfl of size: 1024 2025-09-11 21:25:05,872 Generated random file: owgghoioft of size: 1024 2025-09-11 21:25:05,872 Generated random file: oqhniqquqv of size: 1024 2025-09-11 21:25:05,873 Generated random file: ulbqglocnc of size: 1024 2025-09-11 21:25:05,873 Generated random file: ppbgmlbmtw of size: 1024 2025-09-11 21:25:05,873 Generated random file: awjlrminil of size: 1024 2025-09-11 21:25:05,873 Generated random file: wxccliywvt of size: 1024 2025-09-11 21:25:05,873 Generated random file: riqvrseclw of size: 1024 2025-09-11 21:25:05,873 Generated random file: euqixyvezo of size: 1024 2025-09-11 21:25:05,873 Requests: https://server4:443/qxcomfdpuj https://server4:443/fjxvatwsaq https://server4:443/vkujqxzsfk https://server4:443/abpujbluzj https://server4:443/ynhqqwtmzh https://server4:443/qsjypgrqys https://server4:443/tgngsruxic https://server4:443/ysjpftzbvj https://server4:443/nzvgbvqkwu https://server4:443/kitdnmyzvg https://server4:443/tpmqhqgmot https://server4:443/asckymdohp https://server4:443/jfbctrpgvs https://server4:443/kdrezyxfht https://server4:443/bxeehsvjhv https://server4:443/ctoufcznzb https://server4:443/yszmscdjwu https://server4:443/eihctnjkvw https://server4:443/nluydoeexk https://server4:443/yaruhpfpac https://server4:443/pkvfxootya https://server4:443/iavfctnhlm https://server4:443/friyrnljtp https://server4:443/vfzvyuzozm https://server4:443/ydnhzakist https://server4:443/jdjbgeuogk https://server4:443/lbujjdzvjb https://server4:443/arnmltfkvx https://server4:443/zwxrdwvnnb https://server4:443/rcuxlsoiur https://server4:443/ohrmbxpmkl https://server4:443/ogzeowscsg https://server4:443/upgnrimgah https://server4:443/ielqpxfzex https://server4:443/lfanzqfetl https://server4:443/npovlkzidw https://server4:443/xexyyxaxnk https://server4:443/arcvbujkcq https://server4:443/mluoapcmem https://server4:443/foxudzjcjl https://server4:443/gbdwckwjhy https://server4:443/yhvngkllfl https://server4:443/owgghoioft https://server4:443/oqhniqquqv https://server4:443/ulbqglocnc https://server4:443/ppbgmlbmtw https://server4:443/awjlrminil https://server4:443/wxccliywvt https://server4:443/riqvrseclw https://server4:443/euqixyvezo 2025-09-11 21:25:05,936 2025-09-11 21:25:05,936 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_6pdpz1qd/ TESTCASE_SERVER=multiconnect TESTCASE_CLIENT=multiconnect WWW=/tmp/www__h1d0a1i/ DOWNLOADS=/tmp/download_06gpb24f/ SERVER_LOGS=/tmp/logs_server_p6x3tmz1 CLIENT_LOGS=/tmp/logs_client_0mtht5xb SCENARIO="corrupt-rate --delay=15ms --bandwidth=10Mbps --queue=25 --rate_to_server=30 --rate_to_client=30 --burst_to_server=3 --burst_to_client=3" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/alibaba/xquic/xquic-interop:latest REQUESTS="https://server4:443/qxcomfdpuj https://server4:443/fjxvatwsaq https://server4:443/vkujqxzsfk https://server4:443/abpujbluzj https://server4:443/ynhqqwtmzh https://server4:443/qsjypgrqys https://server4:443/tgngsruxic https://server4:443/ysjpftzbvj https://server4:443/nzvgbvqkwu https://server4:443/kitdnmyzvg https://server4:443/tpmqhqgmot https://server4:443/asckymdohp https://server4:443/jfbctrpgvs https://server4:443/kdrezyxfht https://server4:443/bxeehsvjhv https://server4:443/ctoufcznzb https://server4:443/yszmscdjwu https://server4:443/eihctnjkvw https://server4:443/nluydoeexk https://server4:443/yaruhpfpac https://server4:443/pkvfxootya https://server4:443/iavfctnhlm https://server4:443/friyrnljtp https://server4:443/vfzvyuzozm https://server4:443/ydnhzakist https://server4:443/jdjbgeuogk https://server4:443/lbujjdzvjb https://server4:443/arnmltfkvx https://server4:443/zwxrdwvnnb https://server4:443/rcuxlsoiur https://server4:443/ohrmbxpmkl https://server4:443/ogzeowscsg https://server4:443/upgnrimgah https://server4:443/ielqpxfzex https://server4:443/lfanzqfetl https://server4:443/npovlkzidw https://server4:443/xexyyxaxnk https://server4:443/arcvbujkcq https://server4:443/mluoapcmem https://server4:443/foxudzjcjl https://server4:443/gbdwckwjhy https://server4:443/yhvngkllfl https://server4:443/owgghoioft https://server4:443/oqhniqquqv https://server4:443/ulbqglocnc https://server4:443/ppbgmlbmtw https://server4:443/awjlrminil https://server4:443/wxccliywvt https://server4:443/riqvrseclw https://server4:443/euqixyvezo" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-09-11 21:25:19,766 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Setting up routes... client | Actual changes: client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | ./demo_server -l d -L /logs/server.log -p 443 -D /www -k /logs/keys.log -i -M server | option log level :d server | option log directory :/logs/server.log server | option port :443 server | option read dir :/www server | option key output file: /logs/keys.log server | set interop mode server | option multipath enabled server | /logs/keys.log 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 multiconnect ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | create ipv4 socket fd: 9 server | create ipv6 socket fd: 10 client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 501.14701ms sim | Using scenario: corrupt-rate --delay=15ms --bandwidth=10Mbps --queue=25 --rate_to_server=30 --rate_to_client=30 --burst_to_server=3 --burst_to_client=3 sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server4:443/qxcomfdpuj https://server4:443/fjxvatwsaq https://server4:443/vkujqxzsfk https://server4:443/abpujbluzj https://server4:443/ynhqqwtmzh https://server4:443/qsjypgrqys https://server4:443/tgngsruxic https://server4:443/ysjpftzbvj https://server4:443/nzvgbvqkwu https://server4:443/kitdnmyzvg https://server4:443/tpmqhqgmot https://server4:443/asckymdohp https://server4:443/jfbctrpgvs https://server4:443/kdrezyxfht https://server4:443/bxeehsvjhv https://server4:443/ctoufcznzb https://server4:443/yszmscdjwu https://server4:443/eihctnjkvw https://server4:443/nluydoeexk https://server4:443/yaruhpfpac https://server4:443/pkvfxootya https://server4:443/iavfctnhlm https://server4:443/friyrnljtp https://server4:443/vfzvyuzozm https://server4:443/ydnhzakist https://server4:443/jdjbgeuogk https://server4:443/lbujjdzvjb https://server4:443/arnmltfkvx https://server4:443/zwxrdwvnnb https://server4:443/rcuxlsoiur https://server4:443/ohrmbxpmkl https://server4:443/ogzeowscsg https://server4:443/upgnrimgah https://server4:443/ielqpxfzex https://server4:443/lfanzqfetl https://server4:443/npovlkzidw https://server4:443/xexyyxaxnk https://server4:443/arcvbujkcq https://server4:443/mluoapcmem https://server4:443/foxudzjcjl https://server4:443/gbdwckwjhy https://server4:443/yhvngkllfl https://server4:443/owgghoioft https://server4:443/oqhniqquqv https://server4:443/ulbqglocnc https://server4:443/ppbgmlbmtw https://server4:443/awjlrminil https://server4:443/wxccliywvt https://server4:443/riqvrseclw https://server4:443/euqixyvezo' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test multiconnect --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/qxcomfdpuj https://server4:443/fjxvatwsaq https://server4:443/vkujqxzsfk https://server4:443/abpujbluzj https://server4:443/ynhqqwtmzh https://server4:443/qsjypgrqys https://server4:443/tgngsruxic https://server4:443/ysjpftzbvj https://server4:443/nzvgbvqkwu https://server4:443/kitdnmyzvg https://server4:443/tpmqhqgmot https://server4:443/asckymdohp https://server4:443/jfbctrpgvs https://server4:443/kdrezyxfht https://server4:443/bxeehsvjhv https://server4:443/ctoufcznzb https://server4:443/yszmscdjwu https://server4:443/eihctnjkvw https://server4:443/nluydoeexk https://server4:443/yaruhpfpac https://server4:443/pkvfxootya https://server4:443/iavfctnhlm https://server4:443/friyrnljtp https://server4:443/vfzvyuzozm https://server4:443/ydnhzakist https://server4:443/jdjbgeuogk https://server4:443/lbujjdzvjb https://server4:443/arnmltfkvx https://server4:443/zwxrdwvnnb https://server4:443/rcuxlsoiur https://server4:443/ohrmbxpmkl https://server4:443/ogzeowscsg https://server4:443/upgnrimgah https://server4:443/ielqpxfzex https://server4:443/lfanzqfetl https://server4:443/npovlkzidw https://server4:443/xexyyxaxnk https://server4:443/arcvbujkcq https://server4:443/mluoapcmem https://server4:443/foxudzjcjl https://server4:443/gbdwckwjhy https://server4:443/yhvngkllfl https://server4:443/owgghoioft https://server4:443/oqhniqquqv https://server4:443/ulbqglocnc https://server4:443/ppbgmlbmtw https://server4:443/awjlrminil https://server4:443/wxccliywvt https://server4:443/riqvrseclw 'https://server4:443/euqixyvezo client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is Ok(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:59227 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=2510e04cd6e1d78b client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=8 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:59227->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:2510e04cd6e1d78b 0.0.0.0:59227->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:2510e04cd6e1d78b 0.0.0.0:59227->193.167.100.100:443] Path validated Instant { tv_sec: 679, tv_nsec: 827938005 } client | 0.001 DEBUG [Client 2510e04cd6e1d78b] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x561ee8080480] state -> InProgress client | 0.002 DEBUG [Client 2510e04cd6e1d78b] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client 2510e04cd6e1d78b] pn=8 type=Initial pri-path:2510e04cd6e1d78b 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x561ee8093aa0, pn=8, ps=1252 client | 0.002 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=327 client | 0.002 DEBUG [Client 2510e04cd6e1d78b] pn=9 type=Initial pri-path:2510e04cd6e1d78b 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 367 client | TX -> Crypto { offset: 1213, len: 327 } client | 0.002 DEBUG [Client 2510e04cd6e1d78b] pad Initial from 367 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x561ee8093aa0, pn=9, ps=1252 client | 0.002 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) 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 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) 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 2510e04cd6e1d78b] delay duration 3.852298ms client | 0.002 DEBUG Setting timeout of 3.852298ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) 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 2510e04cd6e1d78b] delay duration 3.817954ms client | 0.002 DEBUG Setting timeout of 3.817954ms client | 0.007 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: 2510e04cd6e1d78b) 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 2510e04cd6e1d78b] delay duration 294.335195ms client | 0.007 DEBUG Setting timeout of 294.335195ms sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/1 (0.0%) sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/2 (0.0%) sim | Forwarding 47 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/1 (0.0%) client | 0.039 DEBUG [Client 2510e04cd6e1d78b] pn=0 type=Initial pri-path:2510e04cd6e1d78b 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 47 client | -> RX Ack { largest_acknowledged: 8, ack_delay: 58, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.039 DEBUG [Client 2510e04cd6e1d78b] Rx ACK space=in, ranges=[8..=8] client | 0.039 DEBUG [recovery::Loss] ACK for Initial - largest_acked=8 client | 0.039 DEBUG on_packets_acked this=0x561ee8093aa0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.039 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 0.039 DEBUG [Client 2510e04cd6e1d78b] Changing to use Server CID=c19deec57c41ab0821bce548 client | 0.039 DEBUG [Client 2510e04cd6e1d78b] State change from WaitInitial -> WaitVersion client | 0.039 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client 2510e04cd6e1d78b] delay duration 74.808143ms client | 0.039 DEBUG Setting timeout of 74.808143ms client | 0.039 WARN Unhandled event StateChange(WaitVersion) client | 0.039 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client 2510e04cd6e1d78b] delay duration 74.773919ms client | 0.039 DEBUG Setting timeout of 74.773919ms sim | Forwarding 1200 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/2 (0.0%) client | 0.040 DEBUG [Client 2510e04cd6e1d78b] pn=1 type=Initial pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Padding { len: 1064 } sim | Forwarding 183 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/3 (0.0%) client | 0.041 DEBUG Write secret available for Handshake: SymKey [32]: fdaccab91a88bb0dceaf77a736b14735f08dc4a8971abe4185b8686fc7084cac client | 0.041 DEBUG Read secret available for Handshake: SymKey [32]: 7e5d9d5ffefa2f321c6bca03f9e337ef71487ad48feaf540e6146a8562dc8126 client | 0.041 DEBUG [Agent 0x561ee8080480] state -> InProgress client | 0.041 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.041 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.041 DEBUG [Crypto] Handshake keys installed client | 0.041 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 867756449 } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] State change from WaitVersion -> Handshaking client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=10 type=Initial pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 44 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 55, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pad Initial from 44 to PLPMTU 1252 client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] delay duration 72.722035ms client | 0.041 DEBUG Setting timeout of 72.722035ms client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=0 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 183 client | -> RX Crypto { offset: 0, len: 138 } client | 0.041 DEBUG [Agent 0x561ee8080480] state -> InProgress client | 0.041 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 868293978 } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=0 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 4, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] Drop packet number space in sim | Forwarding 516 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/4 (0.0%) sim | Forwarding 125 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/5 (0.0%) sim | Forwarding 81 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 0/6 (0.0%) sim | Corrupting 48 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 32 0xce -> 0x66, corrupted 1/7 (14.3%) client | 0.041 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] delay duration 112.368157ms client | 0.041 DEBUG Setting timeout of 112.368157ms client | 0.041 DEBUG StateChange(Handshaking) client | 0.041 WARN Cannot create stream ConnectionState client | 0.041 DEBUG stream BiDi creatable client | 0.041 WARN Cannot create stream ConnectionState client | 0.041 DEBUG stream UniDi creatable client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] delay duration 112.342459ms client | 0.041 DEBUG Setting timeout of 112.342459ms client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=1 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 516 client | -> RX Crypto { offset: 138, len: 470 } client | 0.041 DEBUG [Agent 0x561ee8080480] state -> AuthenticationPending client | 0.041 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 868480876 } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=1 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 2510e04cd6e1d78b] delay duration 112.118372ms client | 0.041 DEBUG Setting timeout of 112.118372ms client | 0.041 DEBUG [Client 2510e04cd6e1d78b] pn=2 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 125 client | -> RX Crypto { offset: 608, len: 79 } client | 0.042 DEBUG [Agent 0x561ee8080480] state -> AuthenticationPending client | 0.042 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 868685647 } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.042 DEBUG [Client 2510e04cd6e1d78b] pn=2 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 44 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 75, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] delay duration 111.436644ms client | 0.042 DEBUG Setting timeout of 111.436644ms client | 0.042 DEBUG [Client 2510e04cd6e1d78b] pn=3 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 81 client | -> RX Crypto { offset: 687, len: 36 } client | 0.042 DEBUG [Agent 0x561ee8080480] state -> AuthenticationPending client | 0.042 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 869365451 } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.042 DEBUG [Client 2510e04cd6e1d78b] pn=3 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 6, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG [Client 2510e04cd6e1d78b] delay duration 111.295522ms client | 0.042 DEBUG Setting timeout of 111.295522ms client | 0.042 DEBUG [Client 2510e04cd6e1d78b] Authenticated Ok client | 0.042 DEBUG Write secret available for ApplicationData: SymKey [32]: 7b7d59a13240aa7044a02da008262233a168338c8d35afa3a7131154b005e428 client | 0.042 DEBUG Read secret available for ApplicationData: SymKey [32]: 8880fe02b2463b3b020b7b9877c5c6a5f381d76279a3fa6b0710a957829f565e client | 0.042 DEBUG [Agent 0x561ee8080480] SSL_AuthCertificateComplete: Ok(()) client | 0.042 DEBUG [Agent 0x561ee8080480] 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 | 0.042 DEBUG [Client 2510e04cd6e1d78b] TLS connection complete client | 0.042 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.042 DEBUG [Crypto] Application write key installed client | 0.042 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.042 DEBUG [Crypto] application read keys installed client | 0.042 DEBUG [Client 2510e04cd6e1d78b] State change from Handshaking -> Connected client | 0.042 INFO [Client 2510e04cd6e1d78b] Connection established client | 0.042 DEBUG stream BiDi creatable client | 0.042 INFO Created stream 0 for https://server4/qxcomfdpuj client | 0.042 INFO Saving https://server4/qxcomfdpuj to "/downloads/qxcomfdpuj" client | 0.042 DEBUG stream UniDi creatable client | 0.042 DEBUG StateChange(Connected) client | 0.042 DEBUG stream 0 writable client | 0.043 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.043 DEBUG CRYPTO for hs offset=0, len=36 client | 0.043 DEBUG [Client 2510e04cd6e1d78b] pn=4 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 77 client | TX -> Crypto { offset: 0, len: 36 } client | 0.043 DEBUG packet_sent this=0x561ee8093aa0, pn=4, ps=77 client | 0.043 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.043 DEBUG [Client 2510e04cd6e1d78b] pn=0 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 127 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.043 DEBUG packet_sent this=0x561ee8093aa0, pn=0, ps=50 client | 0.043 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.043 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client 2510e04cd6e1d78b] delay duration 112.343489ms client | 0.043 DEBUG Setting timeout of 112.343489ms sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/3 (0.0%) sim | Forwarding 43 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/4 (0.0%) sim | Forwarding 43 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/5 (0.0%) sim | Forwarding 44 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 0/6 (0.0%) sim | Corrupting 43 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 38 0xdf -> 0x44, corrupted 1/7 (14.3%) sim | Forwarding 127 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/8 (12.5%) server | xqc_hq_parse_req|247||hq recv CR LF| sim | Corrupting 22 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 12 0x46 -> 0xec, corrupted 2/8 (25.0%) sim | Corrupting 32 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 31 0xb6 -> 0x90, corrupted 3/9 (33.3%) sim | Forwarding 282 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 3/10 (30.0%) client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=2 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 282 client | -> RX Crypto { offset: 0, len: 257 } client | 0.075 DEBUG [0x561ee8080480] Got resumption token [920]: 0200063e8d2bdd57..83631bfbd1ba07af client | 0.075 DEBUG [Agent 0x561ee8080480] 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 | 0.075 DEBUG setting max_stream_data to 16777216 client | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 901948135 } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=1 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 35 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 17, first_ack_range: 0, ack_ranges: [], ecn_count: None } sim | Forwarding 283 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 3/11 (27.3%) sim | Forwarding 48 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 3/12 (25.0%) sim | Corrupting 53 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 15 0x18 -> 0x29, corrupted 4/13 (30.8%) sim | Forwarding 53 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 4/14 (28.6%) client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 80.151965ms client | 0.075 DEBUG Setting timeout of 80.151965ms client | 0.075 DEBUG stream BiDi creatable client | 0.075 DEBUG stream UniDi creatable client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 80.121077ms client | 0.075 DEBUG Setting timeout of 80.121077ms client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=3 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 283 client | -> RX Crypto { offset: 257, len: 257 } client | 0.075 DEBUG [0x561ee8080480] Got resumption token [920]: 0200063e8d2bdd58..0cde66cb3bebd7e4 client | 0.075 DEBUG [Agent 0x561ee8080480] 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 | 0.075 DEBUG setting max_stream_data to 16777216 client | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 922228546 } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 19.918027ms client | 0.075 DEBUG Setting timeout of 19.918027ms client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=4 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 48 client | -> RX Ack { largest_acknowledged: 4, ack_delay: 63, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 2 }], ecn_count: None } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] Rx ACK space=hs, ranges=[4..=4, 0..=2] client | 0.075 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=4 client | 0.075 DEBUG on_packets_acked this=0x561ee8093aa0, limited=1, bytes_in_flight=50, cwnd=12520, state=SlowStart, new_acked=77 client | 0.075 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 8.514907ms client | 0.075 DEBUG Setting timeout of 8.514907ms client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=5 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 53 client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [163, 172, 4, 173, 134, 150, 208, 0, 151, 207, 152, 194], stateless_reset_token: [179, 145, 48, 215, 201, 247, 205, 216, 88, 49, 187, 13, 135, 49, 169, 153] } client | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 902385448 } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG [Client 2510e04cd6e1d78b] pn=2 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 37 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 2, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 8.433164ms client | 0.075 DEBUG Setting timeout of 8.433164ms client | 0.075 DEBUG stream BiDi creatable client | 0.075 DEBUG stream UniDi creatable client | 0.075 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client 2510e04cd6e1d78b] delay duration 8.403409ms client | 0.075 DEBUG Setting timeout of 8.403409ms sim | Forwarding 1049 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 4/15 (26.7%) client | 0.076 DEBUG [Client 2510e04cd6e1d78b] pn=6 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1049 client | -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: true } client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 679, tv_nsec: 923234189 } client | 0.076 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.076 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client 2510e04cd6e1d78b] delay duration 7.619839ms client | 0.076 DEBUG Setting timeout of 7.619839ms client | 0.076 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.076 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client 2510e04cd6e1d78b] delay duration 7.572802ms client | 0.076 DEBUG Setting timeout of 7.572802ms client | 0.076 DEBUG [Client 2510e04cd6e1d78b] State change from Connected -> Closing { error: Application(0), timeout: Instant { tv_sec: 680, tv_nsec: 197624696 } } client | 0.076 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 680, tv_nsec: 197624696 } }) client | 0.076 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.076 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 679, tv_nsec: 903337021 } client | 0.076 DEBUG [Client 2510e04cd6e1d78b] pn=5 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 125, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.076 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.076 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 679, tv_nsec: 903337021 } client | 0.076 DEBUG [Client 2510e04cd6e1d78b] pn=3 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 96 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 12, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.076 DEBUG Setting timeout of 294.218166ms sim | Forwarding 35 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/9 (11.1%) sim | Forwarding 37 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/10 (10.0%) sim | Forwarding 96 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/11 (9.1%) sim | Forwarding 27 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 4/16 (25.0%) client | 0.099 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.099 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.099 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 679, tv_nsec: 926430616 } client | 0.099 DEBUG [Client 2510e04cd6e1d78b] pn=6 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3011, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.099 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.099 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 679, tv_nsec: 926430616 } client | 0.099 DEBUG [Client 2510e04cd6e1d78b] pn=4 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 97 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 2899, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.099 DEBUG Setting timeout of 271.064348ms client | 0.099 DEBUG Setting timeout of 271.052426ms sim | Forwarding 22 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 4/17 (23.5%) sim | Forwarding 32 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 4/18 (22.2%) client | 0.106 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.106 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 679, tv_nsec: 933171134 } client | 0.106 DEBUG [Client 2510e04cd6e1d78b] pn=7 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3854, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.106 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.106 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 679, tv_nsec: 933171134 } client | 0.106 DEBUG [Client 2510e04cd6e1d78b] pn=5 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 97 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 3742, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.106 DEBUG Setting timeout of 264.3771ms client | 0.106 DEBUG [Client 2510e04cd6e1d78b] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.106 DEBUG Building Handshake dcid Some(CID [12]: c19deec57c41ab0821bce548) scid Some(CID [0]: ) client | 0.106 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 679, tv_nsec: 933256463 } client | 0.106 DEBUG [Client 2510e04cd6e1d78b] pn=8 type=Handshake pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 48 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3865, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 0.106 DEBUG Building Short dcid Some(CID [12]: c19deec57c41ab0821bce548) client | 0.106 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 679, tv_nsec: 933256463 } client | 0.106 DEBUG [Client 2510e04cd6e1d78b] pn=6 type=Short pri-path:c19deec57c41ab0821bce548 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 97 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 3752, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.106 DEBUG Setting timeout of 264.304475ms client | 0.106 DEBUG Setting timeout of 264.298363ms sim | Corrupting 25 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 14 0xd4 -> 0x8f, corrupted 5/19 (26.3%) sim | Forwarding 97 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/12 (8.3%) sim | Forwarding 97 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/13 (7.7%) sim | Forwarding 97 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 1/14 (7.1%) server | send_count:14, lost_count:2, tlp_count:0, recv_count:13, srtt:32463 early_data_flag:0, conn_err:12, ack_info:#6-0#0-0#0-0#v0429, path_info:0/1/0/a/0,1,1,1,0,0,0,0,0,0,0,19,21,13,1024,0,17,i32,4,36,97,0,5,98,0,2,27,97,0,8,98,0,4,36,97,0,6,98,0,4,9,40000,10,68,4,6,80000,8,67,4,16,40,9,67,0-2,0-2,0-0,0-0,0-0,0-32,0-4128,0-4472,0-14,0-13,0-2,0-0,0-0,0-0,0-0,0-0,0-0,0-0 client | 0.372 DEBUG [Client 2510e04cd6e1d78b] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 680, tv_nsec: 197624696 } } -> Closed(Application(0)) client | 0.372 INFO Closing timer expired client | 0.372 DEBUG Output::None client | 0.372 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.372 DEBUG Timer fired while closed client | 0.372 DEBUG Output::None client | 0.373 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=f63713400385ee95530294c60546df4803 client | 0.373 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=9 client | 0.373 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.373 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.373 DEBUG [unv-path 0.0.0.0:59227->193.167.100.100:443] Make permanent client | 0.373 DEBUG [unv-path:f63713400385ee95530294c60546df4803 0.0.0.0:59227->193.167.100.100:443] set as primary path client | 0.373 DEBUG [pri-unv-path:f63713400385ee95530294c60546df4803 0.0.0.0:59227->193.167.100.100:443] Path validated Instant { tv_sec: 680, tv_nsec: 199921965 } client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] client_start client | 0.373 DEBUG Writing transport parameters, msg=1 client | 0.373 DEBUG [Agent 0x561ee80afee0] state -> InProgress client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] State change from Init -> WaitInitial client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.373 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.373 DEBUG CRYPTO for in offset=0, len=1204 client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] pn=9 type=Initial pri-path:f63713400385ee95530294c60546df4803 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1204 } client | 0.373 DEBUG packet_sent this=0x561ee8093aa0, pn=9, ps=1252 client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.373 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.373 DEBUG CRYPTO for in offset=1204, len=336 client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] pn=10 type=Initial pri-path:f63713400385ee95530294c60546df4803 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 385 client | TX -> Crypto { offset: 1204, len: 336 } client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 385 to PLPMTU 1252 client | 0.373 DEBUG packet_sent this=0x561ee8093aa0, pn=10, ps=1252 client | 0.373 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.373 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.373 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.374 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.374 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.374 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.374 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 4.059463ms client | 0.374 DEBUG Setting timeout of 4.059463ms client | 0.374 DEBUG StateChange(WaitInitial) client | 0.374 WARN Cannot create stream ConnectionState client | 0.374 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.374 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.374 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.374 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 4.026762ms client | 0.374 DEBUG Setting timeout of 4.026762ms client | 0.379 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.379 DEBUG Building Initial dcid Some(CID [17]: f63713400385ee95530294c60546df4803) scid Some(CID [0]: ) client | 0.379 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.379 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 294.375539ms client | 0.379 DEBUG Setting timeout of 294.375539ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 44 0xaf -> 0x57, corrupted 2/15 (13.3%) sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 2/16 (12.5%) sim | Forwarding 47 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 5/20 (25.0%) client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] pn=0 type=Initial pri-path:f63713400385ee95530294c60546df4803 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 47 client | -> RX Ack { largest_acknowledged: 10, ack_delay: 46, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] Rx ACK space=in, ranges=[10..=10] client | 0.406 DEBUG [recovery::Loss] ACK for Initial - largest_acked=10 client | 0.406 DEBUG on_packets_acked this=0x561ee8093aa0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.406 DEBUG Acked crypto frame space=in offset=1204 length=336 client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] Changing to use Server CID=872079ce4cff23d200815fd5 client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] State change from WaitInitial -> WaitVersion client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.406 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 4.113349ms client | 0.406 DEBUG Setting timeout of 4.113349ms client | 0.406 WARN Unhandled event StateChange(WaitVersion) client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.406 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.406 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 4.090637ms client | 0.406 DEBUG Setting timeout of 4.090637ms client | 0.412 DEBUG packet_lost this=0x561ee8093aa0, pn=9, ps=1252 client | 0.412 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/8764 ssthresh 8764] Cong event -> recovery; cwnd 8764, ssthresh 8764 client | 0.412 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/8764 ssthresh 8764] state -> RecoveryStart client | 0.412 DEBUG on_packets_lost this=0x561ee8093aa0, bytes_in_flight=0, cwnd=8764, state=RecoveryStart client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 0.412 INFO Lost crypto frame space=in offset=0 length=1204 client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.412 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.412 DEBUG CRYPTO for in offset=0, len=1204 client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] pn=11 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1247 client | TX -> Crypto { offset: 0, len: 1204 } client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 1247 to PLPMTU 1252 client | 0.412 DEBUG packet_sent this=0x561ee8093aa0, pn=11, ps=1252 client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.412 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.412 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.412 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.412 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.412 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 100.118974ms client | 0.412 DEBUG Setting timeout of 100.118974ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 22 0x65 -> 0xff, corrupted 3/17 (17.6%) client | 0.513 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 0.513 INFO Lost crypto frame space=in offset=0 length=1204 client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.513 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.513 DEBUG CRYPTO for in offset=0, len=1204 client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] pn=12 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1247 client | TX -> Crypto { offset: 0, len: 1204 } client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 1247 to PLPMTU 1252 client | 0.513 DEBUG packet_sent this=0x561ee8093aa0, pn=12, ps=1252 client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.513 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.513 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.513 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 200.341299ms client | 0.513 DEBUG Setting timeout of 200.341299ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 39 0xf7 -> 0xb7, corrupted 4/18 (22.2%) client | 0.714 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.714 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 0.714 INFO Lost crypto frame space=in offset=0 length=1204 client | 0.714 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.714 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.714 DEBUG CRYPTO for in offset=0, len=1204 client | 0.714 DEBUG [Client f63713400385ee95530294c60546df4803] pn=13 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1247 client | TX -> Crypto { offset: 0, len: 1204 } client | 0.715 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 1247 to PLPMTU 1252 client | 0.715 DEBUG packet_sent this=0x561ee8093aa0, pn=13, ps=1252 client | 0.715 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.715 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.715 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.715 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.715 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 0.715 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.715 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 400.700811ms client | 0.715 DEBUG Setting timeout of 400.700811ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 36 0xa5 -> 0x25, corrupted 5/19 (26.3%) client | 1.117 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 1.117 INFO Lost crypto frame space=in offset=0 length=1204 client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.117 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.117 DEBUG CRYPTO for in offset=0, len=1204 client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] pn=14 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1247 client | TX -> Crypto { offset: 0, len: 1204 } client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 1247 to PLPMTU 1252 client | 1.117 DEBUG packet_sent this=0x561ee8093aa0, pn=14, ps=1252 client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.117 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.117 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.117 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.117 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 801.605633ms client | 1.117 DEBUG Setting timeout of 801.605633ms sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 5/20 (25.0%) sim | Corrupting 1200 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 18 0xd5 -> 0x49, corrupted 6/21 (28.6%) sim | Corrupting 192 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 40 0xac -> 0xc7, corrupted 7/22 (31.8%) sim | Forwarding 516 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 7/23 (30.4%) sim | Corrupting 124 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 39 0x32 -> 0x1b, corrupted 8/24 (33.3%) sim | Corrupting 81 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 37 0x54 -> 0x99, corrupted 9/25 (36.0%) sim | Forwarding 50 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/26 (34.6%) client | 1.152 DEBUG saving Handshake datagram of 516 bytes client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 767.340008ms client | 1.152 DEBUG Setting timeout of 767.340008ms client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 767.300755ms client | 1.152 DEBUG Setting timeout of 767.300755ms client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] pn=2 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 50 client | -> RX Ack { largest_acknowledged: 14, ack_delay: 117, first_ack_range: 0, ack_ranges: [AckRange { gap: 2, range: 0 }], ecn_count: None } client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] Rx ACK space=in, ranges=[14..=14, 10..=10] client | 1.152 DEBUG [recovery::Loss] ACK for Initial - largest_acked=14 client | 1.152 DEBUG packet_lost this=0x561ee8093aa0, pn=11, ps=1252 client | 1.152 DEBUG packet_lost this=0x561ee8093aa0, pn=12, ps=1252 client | 1.152 DEBUG packet_lost this=0x561ee8093aa0, pn=13, ps=1252 client | 1.152 INFO [Cubic [last_max_cwnd: 7449.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/6134 ssthresh 6134] Cong event -> recovery; cwnd 6134, ssthresh 6134 client | 1.152 DEBUG [Cubic [last_max_cwnd: 7449.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/6134 ssthresh 6134] state -> RecoveryStart client | 1.152 INFO [Cubic [last_max_cwnd: 7449.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/6134 ssthresh 6134] persistent congestion client | 1.152 DEBUG [Cubic [last_max_cwnd: 7449.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 6134] state -> PersistentCongestion client | 1.152 DEBUG on_packets_lost this=0x561ee8093aa0, bytes_in_flight=1252, cwnd=2504, state=PersistentCongestion client | 1.152 DEBUG on_packets_acked this=0x561ee8093aa0, limited=1, bytes_in_flight=0, cwnd=2504, state=PersistentCongestion, new_acked=0 client | 1.152 DEBUG Acked crypto frame space=in offset=0 length=1204 client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 1.152 INFO Lost crypto frame space=in offset=0 length=1204 client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 1.152 INFO Lost crypto frame space=in offset=0 length=1204 client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1204 }) client | 1.152 INFO Lost crypto frame space=in offset=0 length=1204 client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 50.140434ms client | 1.152 DEBUG Setting timeout of 50.140434ms client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.152 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.152 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 50.117661ms client | 1.152 DEBUG Setting timeout of 50.117661ms client | 1.203 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.203 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] pn=15 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 40 client | TX -> Ping client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 42 to PLPMTU 1252 client | 1.203 DEBUG packet_sent this=0x561ee8093aa0, pn=15, ps=1252 client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.203 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.203 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.203 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.203 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.203 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 169.7233ms client | 1.203 DEBUG Setting timeout of 169.7233ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 43 0x0 -> 0xb3, corrupted 6/21 (28.6%) client | 1.374 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.374 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] pn=16 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 40 client | TX -> Ping client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 42 to PLPMTU 1252 client | 1.374 DEBUG packet_sent this=0x561ee8093aa0, pn=16, ps=1252 client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.374 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.374 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.374 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.374 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.374 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 339.553979ms client | 1.374 DEBUG Setting timeout of 339.553979ms sim | Forwarding 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 6/22 (27.3%) sim | Forwarding 51 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/27 (33.3%) client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] pn=3 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | -> RX Ack { largest_acknowledged: 16, ack_delay: 25, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }, AckRange { gap: 2, range: 0 }], ecn_count: None } client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] Rx ACK space=in, ranges=[16..=16, 14..=14, 10..=10] client | 1.406 DEBUG [recovery::Loss] ACK for Initial - largest_acked=16 client | 1.406 DEBUG packet_lost this=0x561ee8093aa0, pn=15, ps=1252 client | 1.406 INFO [Cubic [last_max_cwnd: 2128.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 2504] Cong event -> recovery; cwnd 2504, ssthresh 2504 client | 1.406 DEBUG [Cubic [last_max_cwnd: 2128.4, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 2504] state -> RecoveryStart client | 1.406 DEBUG on_packets_lost this=0x561ee8093aa0, bytes_in_flight=1252, cwnd=2504, state=RecoveryStart client | 1.406 DEBUG [Cubic [last_max_cwnd: 2128.4, k: 0, w_max: 2504, ca_epoch_start: Some(Instant { tv_sec: 681, tv_nsec: 233035336 })] CongCtrl 0/2504 ssthresh 2504] on_packets_acked this=0x561ee8093aa0, limited=0, bytes_in_flight=0, cwnd=2504, state=RecoveryStart, new_acked=0 client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.406 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 41.36065ms client | 1.406 DEBUG Setting timeout of 41.36065ms client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.406 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.406 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.406 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 41.336906ms client | 1.406 DEBUG Setting timeout of 41.336906ms client | 1.448 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.448 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] pn=17 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 40 client | TX -> Ping client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 42 to PLPMTU 1252 client | 1.448 DEBUG packet_sent this=0x561ee8093aa0, pn=17, ps=1252 client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.448 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.448 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.448 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.448 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.448 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 146.80243ms client | 1.448 DEBUG Setting timeout of 146.80243ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 33 0xde -> 0xe9, corrupted 7/23 (30.4%) client | 1.595 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.595 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.595 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.595 DEBUG [Client f63713400385ee95530294c60546df4803] pn=18 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 40 client | TX -> Ping client | 1.596 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 42 to PLPMTU 1252 client | 1.596 DEBUG packet_sent this=0x561ee8093aa0, pn=18, ps=1252 client | 1.596 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.596 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.596 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.596 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.596 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.596 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.596 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 293.692271ms client | 1.596 DEBUG Setting timeout of 293.692271ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 9 0xce -> 0x38, corrupted 8/24 (33.3%) client | 1.891 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.891 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] pn=19 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 40 client | TX -> Ping client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] pad Initial from 42 to PLPMTU 1252 client | 1.891 DEBUG packet_sent this=0x561ee8093aa0, pn=19, ps=1252 client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.891 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.891 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.891 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.891 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.891 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 587.552495ms client | 1.891 DEBUG Setting timeout of 587.552495ms sim | Forwarding 1200 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/28 (32.1%) client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] pn=4 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Padding { len: 1064 } client | 1.903 DEBUG Write secret available for Handshake: SymKey [32]: b5c4781a8afdda2fc5c028c7593a115a4ec5fc97cabad84fea436e82c8d8ac88 client | 1.903 DEBUG Read secret available for Handshake: SymKey [32]: 497ce6302cf8774840be05d74dc46dbc2bdb8f1a6d379d5432d0db876eeb09a7 client | 1.903 DEBUG [Agent 0x561ee80afee0] state -> InProgress client | 1.903 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 1.903 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 1.903 DEBUG [Crypto] Handshake keys installed client | 1.903 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 681, tv_nsec: 729905214 } client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] State change from WaitVersion -> Handshaking client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] process saved for epoch Handshake client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] pn=1 type=Handshake pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 516 client | -> RX Crypto { offset: 147, len: 470 } client | 1.903 DEBUG unmark 0-length range at 0 client | 1.903 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 680, tv_nsec: 979039202 } client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 1.903 DEBUG Building Initial dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] pn=20 type=Initial pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 63, first_ack_range: 2, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: None } client | 1.903 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] pn=0 type=Handshake pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 92 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 93921, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] Drop packet number space in client | 1.903 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 1.903 INFO [recovery::Loss] ignoring in-20 from dropped space client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.903 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.903 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 73.348481ms client | 1.903 DEBUG Setting timeout of 73.348481ms client | 1.903 DEBUG StateChange(Handshaking) client | 1.903 WARN Cannot create stream ConnectionState client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.903 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.903 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.903 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 73.3158ms client | 1.903 DEBUG Setting timeout of 73.3158ms sim | Forwarding 1200 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/29 (31.0%) client | 1.904 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.904 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] pn=1 type=Handshake pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 39 client | TX -> Ping client | 1.904 DEBUG packet_sent this=0x561ee8093aa0, pn=1, ps=41 client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.904 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.904 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 73.388336ms client | 1.904 DEBUG Setting timeout of 73.388336ms client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.904 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.904 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.904 DEBUG [Client f63713400385ee95530294c60546df4803] delay duration 73.357519ms client | 1.904 DEBUG Setting timeout of 73.357519ms sim | Corrupting 1252 bytes 193.167.0.100:59227 -> 193.167.100.100:443 offset 31 0x24 -> 0x49, corrupted 9/25 (36.0%) sim | Forwarding 92 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 9/26 (34.6%) sim | Forwarding 41 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 9/27 (33.3%) sim | Forwarding 45 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/30 (30.0%) client | 1.934 DEBUG [Client f63713400385ee95530294c60546df4803] pn=4 type=Handshake pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 45 client | -> RX ConnectionClose { error_code: Transport(10), frame_type: 0, reason_phrase: "" } client | 1.934 INFO [Client f63713400385ee95530294c60546df4803] ConnectionClose received. Error code: Transport(10) frame type 0 reason client | 1.934 DEBUG [Client f63713400385ee95530294c60546df4803] State change from Handshaking -> Draining { error: Transport(Peer(10)), timeout: Instant { tv_sec: 681, tv_nsec: 981665553 } } client | 1.934 DEBUG [Client f63713400385ee95530294c60546df4803] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.934 DEBUG Building Handshake dcid Some(CID [12]: 872079ce4cff23d200815fd5) scid Some(CID [0]: ) client | 1.934 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 681, tv_nsec: 761311915 } client | 1.934 DEBUG [Client f63713400385ee95530294c60546df4803] pn=2 type=Handshake pri-path:872079ce4cff23d200815fd5 0.0.0.0:59227->193.167.100.100:443 Tos(Cs0, NotEct) len 49 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 6, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }], ecn_count: None } client | TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" } client | 1.934 DEBUG Setting timeout of 220.267377ms client | 1.934 WARN Unhandled event StateChange(Draining { error: Transport(Peer(10)), timeout: Instant { tv_sec: 681, tv_nsec: 981665553 } }) client | 1.934 DEBUG Setting timeout of 220.250957ms client | Error: Transport(Peer(10)) sim | Forwarding 45 bytes 193.167.100.100:443 -> 193.167.0.100:59227, corrupted 9/31 (29.0%) sim | Corrupting 45 bytes 193.167.100.100:443 -> 193.167.0.100:59227 offset 33 0x1 -> 0x74, corrupted 10/32 (31.2%) sim | Forwarding 49 bytes 193.167.0.100:59227 -> 193.167.100.100:443, corrupted 9/28 (32.1%) client exited with code 1 Aborting on container exit... Container server Stopping Container client Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped