2025-04-30 11:23:46,224 Generated random file: fkscieqppz of size: 1024 2025-04-30 11:23:46,225 Generated random file: adgsvttlca of size: 1024 2025-04-30 11:23:46,225 Generated random file: syjrjwnhdr of size: 1024 2025-04-30 11:23:46,225 Generated random file: saeigltjhe of size: 1024 2025-04-30 11:23:46,225 Generated random file: psefmfykay of size: 1024 2025-04-30 11:23:46,225 Generated random file: fyvufysmhs of size: 1024 2025-04-30 11:23:46,225 Generated random file: neajabmnqf of size: 1024 2025-04-30 11:23:46,225 Generated random file: jhkyvljecv of size: 1024 2025-04-30 11:23:46,225 Generated random file: eqlgleauon of size: 1024 2025-04-30 11:23:46,225 Generated random file: alsqmpgios of size: 1024 2025-04-30 11:23:46,226 Generated random file: qcmutavemn of size: 1024 2025-04-30 11:23:46,226 Generated random file: ueqjibhmjc of size: 1024 2025-04-30 11:23:46,226 Generated random file: qvkkatbhho of size: 1024 2025-04-30 11:23:46,226 Generated random file: rdiojxkdoo of size: 1024 2025-04-30 11:23:46,226 Generated random file: jsbfdisszt of size: 1024 2025-04-30 11:23:46,226 Generated random file: spxqesbgop of size: 1024 2025-04-30 11:23:46,226 Generated random file: zjkirbwsof of size: 1024 2025-04-30 11:23:46,226 Generated random file: mjsmnoeutn of size: 1024 2025-04-30 11:23:46,227 Generated random file: yeoyeksbxq of size: 1024 2025-04-30 11:23:46,227 Generated random file: cethhprhha of size: 1024 2025-04-30 11:23:46,227 Generated random file: fciphrsrvu of size: 1024 2025-04-30 11:23:46,227 Generated random file: eioncgqlhx of size: 1024 2025-04-30 11:23:46,227 Generated random file: sejepnawzb of size: 1024 2025-04-30 11:23:46,227 Generated random file: zlyjxxvvpp of size: 1024 2025-04-30 11:23:46,227 Generated random file: xhmgvvcxja of size: 1024 2025-04-30 11:23:46,227 Generated random file: dittzvmtgi of size: 1024 2025-04-30 11:23:46,228 Generated random file: qocfvriokb of size: 1024 2025-04-30 11:23:46,228 Generated random file: lyjqjytnve of size: 1024 2025-04-30 11:23:46,228 Generated random file: jatnkuwqhs of size: 1024 2025-04-30 11:23:46,228 Generated random file: ztwoskbxop of size: 1024 2025-04-30 11:23:46,228 Generated random file: zwfznhomtq of size: 1024 2025-04-30 11:23:46,228 Generated random file: spijonjgyr of size: 1024 2025-04-30 11:23:46,228 Generated random file: pegblubxzh of size: 1024 2025-04-30 11:23:46,228 Generated random file: yokzdynfbv of size: 1024 2025-04-30 11:23:46,228 Generated random file: jcqpfcyjit of size: 1024 2025-04-30 11:23:46,229 Generated random file: mqaqcqpowr of size: 1024 2025-04-30 11:23:46,229 Generated random file: prvwmkqyar of size: 1024 2025-04-30 11:23:46,229 Generated random file: iychctmqvp of size: 1024 2025-04-30 11:23:46,229 Generated random file: styzqdpevh of size: 1024 2025-04-30 11:23:46,229 Generated random file: shsbuwhmgb of size: 1024 2025-04-30 11:23:46,229 Generated random file: wpstviryzd of size: 1024 2025-04-30 11:23:46,229 Generated random file: mskjuygfpe of size: 1024 2025-04-30 11:23:46,229 Generated random file: chvvgapdqn of size: 1024 2025-04-30 11:23:46,230 Generated random file: sutdndtmue of size: 1024 2025-04-30 11:23:46,230 Generated random file: vbexqnoehd of size: 1024 2025-04-30 11:23:46,230 Generated random file: drsmyyaxww of size: 1024 2025-04-30 11:23:46,230 Generated random file: awbrwjwzjk of size: 1024 2025-04-30 11:23:46,230 Generated random file: swslhdhlvt of size: 1024 2025-04-30 11:23:46,230 Generated random file: tfzeggtlii of size: 1024 2025-04-30 11:23:46,230 Generated random file: ngzucjfjoi of size: 1024 2025-04-30 11:23:46,230 Requests: https://server4:443/fkscieqppz https://server4:443/adgsvttlca https://server4:443/syjrjwnhdr https://server4:443/saeigltjhe https://server4:443/psefmfykay https://server4:443/fyvufysmhs https://server4:443/neajabmnqf https://server4:443/jhkyvljecv https://server4:443/eqlgleauon https://server4:443/alsqmpgios https://server4:443/qcmutavemn https://server4:443/ueqjibhmjc https://server4:443/qvkkatbhho https://server4:443/rdiojxkdoo https://server4:443/jsbfdisszt https://server4:443/spxqesbgop https://server4:443/zjkirbwsof https://server4:443/mjsmnoeutn https://server4:443/yeoyeksbxq https://server4:443/cethhprhha https://server4:443/fciphrsrvu https://server4:443/eioncgqlhx https://server4:443/sejepnawzb https://server4:443/zlyjxxvvpp https://server4:443/xhmgvvcxja https://server4:443/dittzvmtgi https://server4:443/qocfvriokb https://server4:443/lyjqjytnve https://server4:443/jatnkuwqhs https://server4:443/ztwoskbxop https://server4:443/zwfznhomtq https://server4:443/spijonjgyr https://server4:443/pegblubxzh https://server4:443/yokzdynfbv https://server4:443/jcqpfcyjit https://server4:443/mqaqcqpowr https://server4:443/prvwmkqyar https://server4:443/iychctmqvp https://server4:443/styzqdpevh https://server4:443/shsbuwhmgb https://server4:443/wpstviryzd https://server4:443/mskjuygfpe https://server4:443/chvvgapdqn https://server4:443/sutdndtmue https://server4:443/vbexqnoehd https://server4:443/drsmyyaxww https://server4:443/awbrwjwzjk https://server4:443/swslhdhlvt https://server4:443/tfzeggtlii https://server4:443/ngzucjfjoi 2025-04-30 11:23:46,293 2025-04-30 11:23:46,293 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_rz55y2ng/ TESTCASE_SERVER=multiconnect TESTCASE_CLIENT=multiconnect WWW=/tmp/www_3rq9cf0a/ DOWNLOADS=/tmp/download_iguy_xpe/ SERVER_LOGS=/tmp/logs_server_vs940zmk CLIENT_LOGS=/tmp/logs_client_1kv4wsle 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=litespeedtech/lsquic-qir:latest REQUESTS="https://server4:443/fkscieqppz https://server4:443/adgsvttlca https://server4:443/syjrjwnhdr https://server4:443/saeigltjhe https://server4:443/psefmfykay https://server4:443/fyvufysmhs https://server4:443/neajabmnqf https://server4:443/jhkyvljecv https://server4:443/eqlgleauon https://server4:443/alsqmpgios https://server4:443/qcmutavemn https://server4:443/ueqjibhmjc https://server4:443/qvkkatbhho https://server4:443/rdiojxkdoo https://server4:443/jsbfdisszt https://server4:443/spxqesbgop https://server4:443/zjkirbwsof https://server4:443/mjsmnoeutn https://server4:443/yeoyeksbxq https://server4:443/cethhprhha https://server4:443/fciphrsrvu https://server4:443/eioncgqlhx https://server4:443/sejepnawzb https://server4:443/zlyjxxvvpp https://server4:443/xhmgvvcxja https://server4:443/dittzvmtgi https://server4:443/qocfvriokb https://server4:443/lyjqjytnve https://server4:443/jatnkuwqhs https://server4:443/ztwoskbxop https://server4:443/zwfznhomtq https://server4:443/spijonjgyr https://server4:443/pegblubxzh https://server4:443/yokzdynfbv https://server4:443/jcqpfcyjit https://server4:443/mqaqcqpowr https://server4:443/prvwmkqyar https://server4:443/iychctmqvp https://server4:443/styzqdpevh https://server4:443/shsbuwhmgb https://server4:443/wpstviryzd https://server4:443/mskjuygfpe https://server4:443/chvvgapdqn https://server4:443/sutdndtmue https://server4:443/vbexqnoehd https://server4:443/drsmyyaxww https://server4:443/awbrwjwzjk https://server4:443/swslhdhlvt https://server4:443/tfzeggtlii https://server4:443/ngzucjfjoi" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:24:32,650 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 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 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 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Setting up routes... server | Actual changes: server | tx-checksumming: off server | tx-checksum-ip-generic: off server | tx-checksum-sctp: off server | tcp-segmentation-offload: off server | tx-tcp-segmentation: off [requested on] server | tx-tcp-ecn-segmentation: off [requested on] server | tx-tcp-mangleid-segmentation: off [requested on] server | tx-tcp6-segmentation: off [requested on] server | tx-udp-segmentation: off [requested on] server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | TEST_PARAMS: server | REQUESTS: '' server | paths: server | server: server | port: server | SERVER_PARAMS: sim | server:443 is available after 1.046326403s 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/fkscieqppz https://server4:443/adgsvttlca https://server4:443/syjrjwnhdr https://server4:443/saeigltjhe https://server4:443/psefmfykay https://server4:443/fyvufysmhs https://server4:443/neajabmnqf https://server4:443/jhkyvljecv https://server4:443/eqlgleauon https://server4:443/alsqmpgios https://server4:443/qcmutavemn https://server4:443/ueqjibhmjc https://server4:443/qvkkatbhho https://server4:443/rdiojxkdoo https://server4:443/jsbfdisszt https://server4:443/spxqesbgop https://server4:443/zjkirbwsof https://server4:443/mjsmnoeutn https://server4:443/yeoyeksbxq https://server4:443/cethhprhha https://server4:443/fciphrsrvu https://server4:443/eioncgqlhx https://server4:443/sejepnawzb https://server4:443/zlyjxxvvpp https://server4:443/xhmgvvcxja https://server4:443/dittzvmtgi https://server4:443/qocfvriokb https://server4:443/lyjqjytnve https://server4:443/jatnkuwqhs https://server4:443/ztwoskbxop https://server4:443/zwfznhomtq https://server4:443/spijonjgyr https://server4:443/pegblubxzh https://server4:443/yokzdynfbv https://server4:443/jcqpfcyjit https://server4:443/mqaqcqpowr https://server4:443/prvwmkqyar https://server4:443/iychctmqvp https://server4:443/styzqdpevh https://server4:443/shsbuwhmgb https://server4:443/wpstviryzd https://server4:443/mskjuygfpe https://server4:443/chvvgapdqn https://server4:443/sutdndtmue https://server4:443/vbexqnoehd https://server4:443/drsmyyaxww https://server4:443/awbrwjwzjk https://server4:443/swslhdhlvt https://server4:443/tfzeggtlii https://server4:443/ngzucjfjoi' ']' 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/fkscieqppz https://server4:443/adgsvttlca https://server4:443/syjrjwnhdr https://server4:443/saeigltjhe https://server4:443/psefmfykay https://server4:443/fyvufysmhs https://server4:443/neajabmnqf https://server4:443/jhkyvljecv https://server4:443/eqlgleauon https://server4:443/alsqmpgios https://server4:443/qcmutavemn https://server4:443/ueqjibhmjc https://server4:443/qvkkatbhho https://server4:443/rdiojxkdoo https://server4:443/jsbfdisszt https://server4:443/spxqesbgop https://server4:443/zjkirbwsof https://server4:443/mjsmnoeutn https://server4:443/yeoyeksbxq https://server4:443/cethhprhha https://server4:443/fciphrsrvu https://server4:443/eioncgqlhx https://server4:443/sejepnawzb https://server4:443/zlyjxxvvpp https://server4:443/xhmgvvcxja https://server4:443/dittzvmtgi https://server4:443/qocfvriokb https://server4:443/lyjqjytnve https://server4:443/jatnkuwqhs https://server4:443/ztwoskbxop https://server4:443/zwfznhomtq https://server4:443/spijonjgyr https://server4:443/pegblubxzh https://server4:443/yokzdynfbv https://server4:443/jcqpfcyjit https://server4:443/mqaqcqpowr https://server4:443/prvwmkqyar https://server4:443/iychctmqvp https://server4:443/styzqdpevh https://server4:443/shsbuwhmgb https://server4:443/wpstviryzd https://server4:443/mskjuygfpe https://server4:443/chvvgapdqn https://server4:443/sutdndtmue https://server4:443/vbexqnoehd https://server4:443/drsmyyaxww https://server4:443/awbrwjwzjk https://server4:443/swslhdhlvt https://server4:443/tfzeggtlii 'https://server4:443/ngzucjfjoi 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:56045 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=769a2b6a3580406b79941ea7d8543d4634b05df9 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:56045->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443] Path validated Instant { tv_sec: 613, tv_nsec: 643402360 } client | 0.001 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x55a420cea2d0] state -> InProgress client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1201 client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=0 type=Initial pri-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1201 } client | 0.002 DEBUG packet_sent this=0x55a420cfdbe0, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1201, len=338 client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=1 type=Initial pri-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 390 client | TX -> Crypto { offset: 1201, len: 338 } client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pad Initial from 390 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55a420cfdbe0, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) 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 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 3.687218ms client | 0.002 DEBUG Setting timeout of 3.687218ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) 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 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 3.652413ms client | 0.002 DEBUG Setting timeout of 3.652413ms client | 0.007 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) 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 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 294.803281ms client | 0.007 DEBUG Setting timeout of 294.803281ms sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 2 0x0 -> 0x23, corrupted 1/1 (100.0%) sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 17 0xa7 -> 0x44, corrupted 2/2 (100.0%) client | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1201 }) client | 0.303 INFO Lost crypto frame space=in offset=0 length=1201 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1201, length: 338 }) client | 0.303 INFO Lost crypto frame space=in offset=1201 length=338 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=0, len=1201 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=2 type=Initial pri-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1201 } client | 0.303 DEBUG packet_sent this=0x55a420cfdbe0, pn=2, ps=1252 client | 0.303 DEBUG ECN probing: sent 3 probes client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=1201, len=338 client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=3 type=Initial pri-path:769a2b6a3580406b79941ea7d8543d4634b05df9 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 390 client | TX -> Crypto { offset: 1201, len: 338 } client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pad Initial from 390 to PLPMTU 1252 client | 0.303 DEBUG packet_sent this=0x55a420cfdbe0, pn=3, ps=1252 client | 0.303 DEBUG ECN probing: sent 4 probes client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [20]: 769a2b6a3580406b79941ea7d8543d4634b05df9) scid Some(CID [0]: ) client | 0.303 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.303 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 599.917647ms client | 0.303 DEBUG Setting timeout of 599.917647ms sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 4 0x1 -> 0x2e, corrupted 3/3 (100.0%) sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 3/4 (75.0%) sim | Forwarding 95 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 0/1 (0.0%) client | 0.341 INFO [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] received Retry client | 0.341 INFO [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Valid Retry received, token=00d20836a763809151db77388577ae06b8c7a6fa902d3bb5f74cbf27adff8b1e292073efdc65d2a2c0ce56e63cc06e0c71e9d07c2bed4f382c90a4a416fe56ae scid=849d7d8be036e020 client | 0.341 INFO [pri-path:849d7d8be036e020 0.0.0.0:56045->193.167.100.100:443] discarding a packet without an RTT estimate; guessing RTT=339.650128ms client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1201 }) client | 0.341 INFO Lost crypto frame space=in offset=0 length=1201 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.341 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1201, length: 338 }) client | 0.341 INFO Lost crypto frame space=in offset=1201 length=338 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1201 }) client | 0.341 INFO Lost crypto frame space=in offset=0 length=1201 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1201, length: 338 }) client | 0.341 INFO Lost crypto frame space=in offset=1201 length=338 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Lost: EcnEct0 client | 0.341 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=849d7d8be036e020 client | 0.341 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.341 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.341 INFO [CryptoStates] Continue packet numbers for initial after retry (write is 0..0) client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.341 DEBUG Building Initial dcid Some(CID [8]: 849d7d8be036e020) scid Some(CID [0]: ) client | 0.341 DEBUG CRYPTO for in offset=0, len=1148 client | 0.341 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=4 type=Initial pri-path:849d7d8be036e020 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1148 } client | 0.341 DEBUG packet_sent this=0x55a420cfdbe0, pn=4, ps=1252 client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.342 DEBUG Building Initial dcid Some(CID [8]: 849d7d8be036e020) scid Some(CID [0]: ) client | 0.342 DEBUG CRYPTO for in offset=1148, len=391 client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=5 type=Initial pri-path:849d7d8be036e020 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 496 client | TX -> Crypto { offset: 1148, len: 391 } client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pad Initial from 496 to PLPMTU 1252 client | 0.342 DEBUG packet_sent this=0x55a420cfdbe0, pn=5, ps=1252 client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.342 DEBUG Building Initial dcid Some(CID [8]: 849d7d8be036e020) scid Some(CID [0]: ) client | 0.342 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.018843625s client | 0.342 DEBUG Setting timeout of 1.018843625s client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.342 DEBUG Building Initial dcid Some(CID [8]: 849d7d8be036e020) scid Some(CID [0]: ) client | 0.342 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.342 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.018812778s client | 0.342 DEBUG Setting timeout of 1.018812778s sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 3/5 (60.0%) sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 3/6 (50.0%) sim | Forwarding 40 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 0/2 (0.0%) client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=0 type=Initial pri-path:849d7d8be036e020 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 40 client | -> RX Ack { largest_acknowledged: 4, ack_delay: 61, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Rx ACK space=in, ranges=[4..=4] client | 0.374 DEBUG [LossRecovery] ACK for Initial - largest_acked=4 client | 0.374 DEBUG on_packets_acked this=0x55a420cfdbe0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.374 DEBUG Acked crypto frame space=in offset=0 length=1148 client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Changing to use Server CID=c468fcf47da93567 client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from WaitInitial -> WaitVersion client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.374 DEBUG Building Initial dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.374 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.085780714s client | 0.374 DEBUG Setting timeout of 1.085780714s client | 0.374 WARN Unhandled event StateChange(WaitVersion) client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.374 DEBUG Building Initial dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.374 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.374 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.085741361s client | 0.374 DEBUG Setting timeout of 1.085741361s sim | Corrupting 1252 bytes 193.167.100.100:443 -> 193.167.0.100:56045 offset 46 0xda -> 0x1a, corrupted 1/3 (33.3%) sim | Corrupting 1252 bytes 193.167.100.100:443 -> 193.167.0.100:56045 offset 27 0x5d -> 0xfe, corrupted 2/4 (50.0%) sim | Forwarding 1252 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 2/5 (40.0%) client | 0.978 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=5 type=Initial pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 135 client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Padding { len: 6 } client | 0.978 DEBUG Read Ok(90) bytes client | 0.978 DEBUG Write secret available for Handshake: SymKey [32]: 2cbcb29a0b8de85f013e0742d3efe0b175ea2a9880845b226c58f71063bcfcb1 client | 0.978 DEBUG Read secret available for Handshake: SymKey [32]: 4ceed8bfa0f9810612539a0a1648540ac473c2f66982b39b94f34f6abfccca1f client | 0.978 DEBUG [Agent 0x55a420cea2d0] state -> InProgress client | 0.978 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.978 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.978 DEBUG [Crypto] Handshake keys installed client | 0.978 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 614, tv_nsec: 620434029 } client | 0.978 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from WaitVersion -> Handshaking client | 0.978 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=6 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 1117 client | -> RX Crypto { offset: 0, len: 733 } client | -> RX Padding { len: 346 } client | 0.978 DEBUG Read Ok(733) bytes client | 0.979 DEBUG [Agent 0x55a420cea2d0] state -> AuthenticationPending client | 0.979 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 614, tv_nsec: 620434029 } client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.979 DEBUG Building Initial dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=6 type=Initial pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 111 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 159, first_ack_range: 0, ack_ranges: [AckRange { gap: 3, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | 0.979 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=0 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 154 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 159, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Drop packet number space in client | 0.979 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.979 WARN [LossRecovery] ignoring in-6 from dropped space client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.979 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.979 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.117899631s client | 0.979 DEBUG Setting timeout of 1.117899631s client | 0.979 DEBUG StateChange(Handshaking) client | 0.979 WARN Cannot create stream ConnectionState client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Authenticated Ok client | 0.979 DEBUG Write secret available for ApplicationData: SymKey [32]: 3477995d4e1624da875e114686ff25882d6b4bcd2ffdced4f5046345fa41e797 client | 0.979 DEBUG Read secret available for ApplicationData: SymKey [32]: 02d6108f74a35468f489e23761f77bf97f1e266c871016bd4bcbd2c1700f9b17 client | 0.979 DEBUG [Agent 0x55a420cea2d0] SSL_AuthCertificateComplete: Ok(()) client | 0.979 DEBUG [Agent 0x55a420cea2d0] 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.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] TLS connection complete client | 0.979 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.979 DEBUG [Crypto] Application write key installed client | 0.979 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.979 DEBUG [Crypto] application read keys installed client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from Handshaking -> Connected client | 0.979 INFO [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Connection established client | 0.979 DEBUG stream BiDi creatable client | 0.979 INFO Created stream 0 for https://server4/fkscieqppz client | 0.979 INFO Saving https://server4/fkscieqppz to "/downloads/fkscieqppz" client | 0.979 DEBUG stream UniDi creatable client | 0.979 DEBUG StateChange(Connected) client | 0.979 DEBUG stream 0 writable client | 0.979 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.979 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.980 DEBUG CRYPTO for hs offset=0, len=36 client | 0.980 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=1 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 0.980 DEBUG packet_sent this=0x55a420cfdbe0, pn=1, ps=73 client | 0.980 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 0.980 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=0 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 128 client | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 50000, ignore_order: false } client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.980 DEBUG packet_sent this=0x55a420cfdbe0, pn=0, ps=55 client | 0.980 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.980 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 0.980 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 0.980 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.980 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 1.117919838s client | 0.980 DEBUG Setting timeout of 1.117919838s sim | Corrupting 154 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 9 0xf4 -> 0xf2, corrupted 4/7 (57.1%) sim | Forwarding 128 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 4/8 (50.0%) sim | Corrupting 595 bytes 193.167.100.100:443 -> 193.167.0.100:56045 offset 36 0x7f -> 0x26, corrupted 3/6 (50.0%) sim | Forwarding 39 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 3/7 (42.9%) client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=8 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 39 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 27, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Rx ACK space=hs, ranges=[1..=1] client | 1.012 DEBUG [LossRecovery] ACK for Handshake - largest_acked=1 client | 1.012 DEBUG on_packets_acked this=0x55a420cfdbe0, limited=1, bytes_in_flight=55, cwnd=12520, state=SlowStart, new_acked=73 client | 1.012 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.012 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.012 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.012 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 268.326698ms client | 1.012 DEBUG Setting timeout of 268.326698ms client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.012 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.012 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.012 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.012 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 268.281113ms client | 1.012 DEBUG Setting timeout of 268.281113ms sim | Forwarding 1252 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 3/8 (37.5%) sim | Forwarding 32 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 3/9 (33.3%) client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=9 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 1252 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 9, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [52, 82, 61, 195, 63, 54, 249, 18], stateless_reset_token: [155, 108, 47, 3, 13, 221, 75, 36, 150, 174, 125, 181, 216, 41, 159, 61] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [102, 82, 63, 204, 22, 247, 52, 163], stateless_reset_token: [42, 128, 85, 141, 132, 131, 102, 112, 12, 83, 164, 238, 186, 179, 12, 181] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [27, 46, 91, 95, 247, 31, 199, 186], stateless_reset_token: [114, 10, 158, 214, 179, 170, 21, 189, 141, 126, 191, 114, 70, 195, 116, 128] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [17, 195, 222, 218, 27, 56, 76, 201], stateless_reset_token: [165, 205, 20, 50, 157, 108, 160, 151, 64, 105, 191, 243, 18, 19, 138, 3] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [41, 47, 77, 175, 90, 35, 180, 91], stateless_reset_token: [49, 133, 194, 68, 95, 226, 182, 51, 218, 14, 25, 61, 230, 158, 202, 233] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [62, 91, 33, 60, 218, 184, 150, 117], stateless_reset_token: [126, 99, 105, 184, 209, 178, 18, 191, 243, 68, 142, 116, 102, 19, 245, 184] } client | -> RX NewToken { token: [1, 213, 195, 116, 109, 116, 122, 48, 169, 68, 58, 185, 249, 27, 105, 70, 90, 80, 207, 219, 190, 252, 142, 93, 89, 36, 233, 73, 242, 86, 170, 156, 118, 250, 108, 245, 187, 205, 163, 246, 165, 122] } client | -> RX Stream { stream_id: 0, offset: 0, len: >>1015, fin: false } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] Rx ACK space=ap, ranges=[0..=0] client | 1.013 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 1.013 DEBUG on_packets_acked this=0x55a420cfdbe0, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=55 client | 1.013 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 614, tv_nsec: 655371459 } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.013 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=1 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 13, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.013 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 234.181247ms client | 1.013 DEBUG Setting timeout of 234.181247ms client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=10 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect1) len 32 client | -> RX Stream { stream_id: 0, offset: 1015, len: 9, fin: true } client | 1.013 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 614, tv_nsec: 675607118 } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.013 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 19.977859ms client | 1.013 DEBUG Setting timeout of 19.977859ms client | 1.013 DEBUG stream 0 complete client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.013 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] delay duration 19.927194ms client | 1.013 DEBUG Setting timeout of 19.927194ms client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from Connected -> Closing { error: Application(0), timeout: Instant { tv_sec: 618, tv_nsec: 58285687 } } client | 1.013 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 618, tv_nsec: 58285687 } }) client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.013 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.013 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 614, tv_nsec: 655712535 } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=2 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 49 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 173, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 1.013 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.013 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 614, tv_nsec: 655712535 } client | 1.013 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=2 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 94 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 1.013 DEBUG Setting timeout of 3.402467826s sim | Corrupting 34 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 12 0x94 -> 0xd4, corrupted 5/9 (55.6%) sim | Forwarding 94 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 5/10 (50.0%) sim | Forwarding 595 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 3/10 (30.0%) sim | Forwarding 22 bytes 193.167.100.100:443 -> 193.167.0.100:56045, corrupted 3/11 (27.3%) client | 1.044 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.044 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.044 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 614, tv_nsec: 687219336 } client | 1.044 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=3 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 49 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 4112, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 1.044 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.044 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 614, tv_nsec: 687219336 } client | 1.045 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=3 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 95 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3951, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 1.045 DEBUG Setting timeout of 3.3709317s client | 1.045 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.045 DEBUG Building Handshake dcid Some(CID [8]: c468fcf47da93567) scid Some(CID [0]: ) client | 1.045 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 614, tv_nsec: 687368614 } client | 1.045 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=4 type=Handshake pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 49 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 4130, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" } client | 1.045 DEBUG Building Short dcid Some(CID [8]: c468fcf47da93567) client | 1.045 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 614, tv_nsec: 687368614 } client | 1.045 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] pn=4 type=Short pri-path:c468fcf47da93567 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 95 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3970, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 1.045 DEBUG Setting timeout of 3.370829209s client | 1.045 DEBUG Setting timeout of 3.370816846s sim | Forwarding 95 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 5/11 (45.5%) sim | Forwarding 95 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 5/12 (41.7%) client | 4.416 DEBUG [Client 769a2b6a3580406b79941ea7d8543d4634b05df9] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 618, tv_nsec: 58285687 } } -> Closed(Application(0)) client | 4.416 INFO Closing timer expired client | 4.416 DEBUG Output::None client | 4.416 WARN Unhandled event StateChange(Closed(Application(0))) client | 4.416 DEBUG Timer fired while closed client | 4.416 DEBUG Output::None client | 4.417 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=5b9b9adb3e6c6fca21cd77 client | 4.417 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 4.417 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 4.417 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 4.417 DEBUG [unv-path 0.0.0.0:56045->193.167.100.100:443] Make permanent client | 4.417 DEBUG [unv-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443] set as primary path client | 4.417 DEBUG [pri-unv-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443] Path validated Instant { tv_sec: 618, tv_nsec: 59299662 } client | 4.417 DEBUG [Client 5b9b9adb3e6c6fca21cd77] client_start client | 4.417 DEBUG Writing transport parameters, msg=1 client | 4.417 DEBUG [Agent 0x55a420cea2d0] state -> InProgress client | 4.417 DEBUG [Client 5b9b9adb3e6c6fca21cd77] State change from Init -> WaitInitial client | 4.417 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.417 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.417 DEBUG CRYPTO for in offset=0, len=1210 client | 4.417 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=0 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 4.417 DEBUG packet_sent this=0x55a420cfdbe0, pn=0, ps=1252 client | 4.417 DEBUG ECN probing: sent 1 probes client | 4.417 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.417 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.418 DEBUG CRYPTO for in offset=1210, len=329 client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=1 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 372 client | TX -> Crypto { offset: 1210, len: 329 } client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pad Initial from 372 to PLPMTU 1252 client | 4.418 DEBUG packet_sent this=0x55a420cfdbe0, pn=1, ps=1252 client | 4.418 DEBUG ECN probing: sent 2 probes client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 4.418 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.418 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 3.949934ms client | 4.418 DEBUG Setting timeout of 3.949934ms client | 4.418 DEBUG StateChange(WaitInitial) client | 4.418 WARN Cannot create stream ConnectionState client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 4.418 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.418 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 4.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 3.926601ms client | 4.418 DEBUG Setting timeout of 3.926601ms client | 4.423 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.423 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.423 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.423 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 294.825639ms client | 4.423 DEBUG Setting timeout of 294.825639ms sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 5/13 (38.5%) sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 49 0x7c -> 0x2, corrupted 6/14 (42.9%) sim | Corrupting 86 bytes 193.167.100.100:443 -> 193.167.0.100:56045 offset 18 0x8d -> 0xe9, corrupted 4/12 (33.3%) client | 4.719 DEBUG [LossRecovery] PTO timer fired for Initial client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 4.719 INFO Lost crypto frame space=in offset=0 length=1210 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: EcnEct0 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1210, length: 329 }) client | 4.719 INFO Lost crypto frame space=in offset=1210 length=329 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: EcnEct0 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 4.719 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.719 DEBUG CRYPTO for in offset=0, len=1210 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=2 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 4.719 DEBUG packet_sent this=0x55a420cfdbe0, pn=2, ps=1252 client | 4.719 DEBUG ECN probing: sent 3 probes client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.719 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.719 DEBUG CRYPTO for in offset=1210, len=329 client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=3 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, Ect0) len 372 client | TX -> Crypto { offset: 1210, len: 329 } client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pad Initial from 372 to PLPMTU 1252 client | 4.719 DEBUG packet_sent this=0x55a420cfdbe0, pn=3, ps=1252 client | 4.719 DEBUG ECN probing: sent 4 probes client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.719 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 4.719 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.719 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 599.891878ms client | 4.719 DEBUG Setting timeout of 599.891878ms sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 9 0xdb -> 0xc5, corrupted 7/15 (46.7%) sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 9 0xdb -> 0x1c, corrupted 8/16 (50.0%) client | 5.321 DEBUG [LossRecovery] PTO timer fired for Initial client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 5.321 INFO Lost crypto frame space=in offset=0 length=1210 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: EcnEct0 client | 5.321 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1210, length: 329 }) client | 5.321 INFO Lost crypto frame space=in offset=1210 length=329 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: EcnEct0 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 5.321 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 5.321 DEBUG CRYPTO for in offset=0, len=1210 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=4 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 5.321 DEBUG packet_sent this=0x55a420cfdbe0, pn=4, ps=1252 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 5.321 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 5.321 DEBUG CRYPTO for in offset=1210, len=329 client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=5 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 372 client | TX -> Crypto { offset: 1210, len: 329 } client | 5.321 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pad Initial from 372 to PLPMTU 1252 client | 5.321 DEBUG packet_sent this=0x55a420cfdbe0, pn=5, ps=1252 client | 5.322 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 5.322 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 5.322 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 5.322 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 1.199925721s client | 5.322 DEBUG Setting timeout of 1.199925721s sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/17 (47.1%) sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/18 (44.4%) client | 6.523 DEBUG [LossRecovery] PTO timer fired for Initial client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 6.523 INFO Lost crypto frame space=in offset=0 length=1210 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1210, length: 329 }) client | 6.523 INFO Lost crypto frame space=in offset=1210 length=329 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 6.523 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 6.523 DEBUG CRYPTO for in offset=0, len=1210 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=6 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 6.523 DEBUG packet_sent this=0x55a420cfdbe0, pn=6, ps=1252 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 6.523 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 6.523 DEBUG CRYPTO for in offset=1210, len=329 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=7 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 372 client | TX -> Crypto { offset: 1210, len: 329 } client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pad Initial from 372 to PLPMTU 1252 client | 6.523 DEBUG packet_sent this=0x55a420cfdbe0, pn=7, ps=1252 client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 6.523 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 6.523 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 6.523 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 2.399811511s client | 6.523 DEBUG Setting timeout of 2.399811511s sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/19 (42.1%) sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/20 (40.0%) client | 8.925 DEBUG [LossRecovery] PTO timer fired for Initial client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 8.925 INFO Lost crypto frame space=in offset=0 length=1210 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1210, length: 329 }) client | 8.925 INFO Lost crypto frame space=in offset=1210 length=329 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 8.925 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 8.925 DEBUG CRYPTO for in offset=0, len=1210 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=8 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 8.925 DEBUG packet_sent this=0x55a420cfdbe0, pn=8, ps=1252 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 8.925 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 8.925 DEBUG CRYPTO for in offset=1210, len=329 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=9 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 372 client | TX -> Crypto { offset: 1210, len: 329 } client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pad Initial from 372 to PLPMTU 1252 client | 8.925 DEBUG packet_sent this=0x55a420cfdbe0, pn=9, ps=1252 client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 8.925 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 8.925 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 8.925 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 4.799926442s client | 8.925 DEBUG Setting timeout of 4.799926442s sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/21 (38.1%) sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 8/22 (36.4%) client | 13.726 DEBUG [LossRecovery] PTO timer fired for Initial client | 13.726 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 13.726 INFO Lost crypto frame space=in offset=0 length=1210 client | 13.726 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1210, length: 329 }) client | 13.726 INFO Lost crypto frame space=in offset=1210 length=329 client | 13.726 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 13.727 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 13.727 DEBUG CRYPTO for in offset=0, len=1210 client | 13.727 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=10 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 13.727 DEBUG packet_sent this=0x55a420cfdbe0, pn=10, ps=1252 client | 13.727 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 13.727 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 13.727 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 13.727 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 9.599792654s client | 13.727 DEBUG Setting timeout of 9.599792654s sim | Corrupting 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443 offset 3 0x0 -> 0x61, corrupted 9/23 (39.1%) client | 23.327 DEBUG [LossRecovery] PTO timer fired for Initial client | 23.328 DEBUG [Client 5b9b9adb3e6c6fca21cd77] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1210 }) client | 23.328 INFO Lost crypto frame space=in offset=0 length=1210 client | 23.328 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 23.328 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 23.328 DEBUG CRYPTO for in offset=0, len=1210 client | 23.328 DEBUG [Client 5b9b9adb3e6c6fca21cd77] pn=11 type=Initial pri-path:5b9b9adb3e6c6fca21cd77 0.0.0.0:56045->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1210 } client | 23.328 DEBUG packet_sent this=0x55a420cfdbe0, pn=11, ps=1252 client | 23.328 DEBUG [Client 5b9b9adb3e6c6fca21cd77] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 23.328 DEBUG Building Initial dcid Some(CID [11]: 5b9b9adb3e6c6fca21cd77) scid Some(CID [0]: ) client | 23.328 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } client | 23.328 DEBUG [Client 5b9b9adb3e6c6fca21cd77] delay duration 11.089260983s client | 23.328 DEBUG Setting timeout of 11.089260983s sim | Forwarding 1252 bytes 193.167.0.100:56045 -> 193.167.100.100:443, corrupted 9/24 (37.5%) client | 34.418 INFO [Client 5b9b9adb3e6c6fca21cd77] idle timeout expired client | 34.418 DEBUG [Client 5b9b9adb3e6c6fca21cd77] State change from WaitInitial -> Closed(Transport(IdleTimeout)) client | 34.418 DEBUG Output::None client | 34.418 WARN Unhandled event StateChange(Closed(Transport(IdleTimeout))) client | 34.418 DEBUG Timer fired while closed client | 34.418 DEBUG Output::None client | Error: TransportError(IdleTimeout) 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