2025-04-30 11:45:47,598 Generated random file: zebjmtpilg of size: 1024
2025-04-30 11:45:47,598 Generated random file: umrjhqlvqd of size: 1024
2025-04-30 11:45:47,598 Generated random file: deiuqtarca of size: 1024
2025-04-30 11:45:47,598 Generated random file: yznmuhknlu of size: 1024
2025-04-30 11:45:47,598 Generated random file: vhjbbvzzfq of size: 1024
2025-04-30 11:45:47,598 Generated random file: gcybssftgj of size: 1024
2025-04-30 11:45:47,599 Generated random file: ahhvifymnj of size: 1024
2025-04-30 11:45:47,599 Generated random file: ulkntklxqx of size: 1024
2025-04-30 11:45:47,599 Generated random file: goowyclqct of size: 1024
2025-04-30 11:45:47,599 Generated random file: ozezvtkuym of size: 1024
2025-04-30 11:45:47,599 Generated random file: jvlmkrdwne of size: 1024
2025-04-30 11:45:47,599 Generated random file: dixfljrjvu of size: 1024
2025-04-30 11:45:47,599 Generated random file: cinqgwmxxy of size: 1024
2025-04-30 11:45:47,599 Generated random file: uamczgjewd of size: 1024
2025-04-30 11:45:47,600 Generated random file: jwnkplhqeg of size: 1024
2025-04-30 11:45:47,600 Generated random file: bqnkcxpcol of size: 1024
2025-04-30 11:45:47,600 Generated random file: yngdomgeck of size: 1024
2025-04-30 11:45:47,600 Generated random file: ftkmquqpda of size: 1024
2025-04-30 11:45:47,600 Generated random file: rsbukwzaot of size: 1024
2025-04-30 11:45:47,600 Generated random file: kgzdkeispi of size: 1024
2025-04-30 11:45:47,600 Generated random file: bckzcifsgy of size: 1024
2025-04-30 11:45:47,600 Generated random file: gbtufujvzj of size: 1024
2025-04-30 11:45:47,601 Generated random file: mzjqpmfcto of size: 1024
2025-04-30 11:45:47,601 Generated random file: oymrzankvu of size: 1024
2025-04-30 11:45:47,601 Generated random file: ajdnrvwwnz of size: 1024
2025-04-30 11:45:47,601 Generated random file: dhutcrbdkg of size: 1024
2025-04-30 11:45:47,601 Generated random file: qwqukuqksn of size: 1024
2025-04-30 11:45:47,601 Generated random file: jidvxrhqfi of size: 1024
2025-04-30 11:45:47,601 Generated random file: qltgglfhbd of size: 1024
2025-04-30 11:45:47,601 Generated random file: thznwhlrpc of size: 1024
2025-04-30 11:45:47,601 Generated random file: zykwfgifjs of size: 1024
2025-04-30 11:45:47,602 Generated random file: ygtinftrtf of size: 1024
2025-04-30 11:45:47,602 Generated random file: mgxotevhoi of size: 1024
2025-04-30 11:45:47,602 Generated random file: lmuhuejetp of size: 1024
2025-04-30 11:45:47,602 Generated random file: lvaagtidcx of size: 1024
2025-04-30 11:45:47,602 Generated random file: ejuqddtvsu of size: 1024
2025-04-30 11:45:47,602 Generated random file: cacslwkfba of size: 1024
2025-04-30 11:45:47,602 Generated random file: bpdnqdjojg of size: 1024
2025-04-30 11:45:47,602 Generated random file: dzobavqcbz of size: 1024
2025-04-30 11:45:47,603 Generated random file: ugittdtqye of size: 1024
2025-04-30 11:45:47,603 Generated random file: gqcrruyctl of size: 1024
2025-04-30 11:45:47,603 Generated random file: hdfcvymxho of size: 1024
2025-04-30 11:45:47,603 Generated random file: xtkgjqmvop of size: 1024
2025-04-30 11:45:47,603 Generated random file: pfurclnalj of size: 1024
2025-04-30 11:45:47,603 Generated random file: nfxvsuehli of size: 1024
2025-04-30 11:45:47,603 Generated random file: nqwwzijuwz of size: 1024
2025-04-30 11:45:47,603 Generated random file: ztwdchcadf of size: 1024
2025-04-30 11:45:47,604 Generated random file: rqgmwbrrir of size: 1024
2025-04-30 11:45:47,604 Generated random file: njlkkgyunr of size: 1024
2025-04-30 11:45:47,604 Generated random file: sdwpmxzrpr of size: 1024
2025-04-30 11:45:47,604 Requests: https://server4:443/zebjmtpilg https://server4:443/umrjhqlvqd https://server4:443/deiuqtarca https://server4:443/yznmuhknlu https://server4:443/vhjbbvzzfq https://server4:443/gcybssftgj https://server4:443/ahhvifymnj https://server4:443/ulkntklxqx https://server4:443/goowyclqct https://server4:443/ozezvtkuym https://server4:443/jvlmkrdwne https://server4:443/dixfljrjvu https://server4:443/cinqgwmxxy https://server4:443/uamczgjewd https://server4:443/jwnkplhqeg https://server4:443/bqnkcxpcol https://server4:443/yngdomgeck https://server4:443/ftkmquqpda https://server4:443/rsbukwzaot https://server4:443/kgzdkeispi https://server4:443/bckzcifsgy https://server4:443/gbtufujvzj https://server4:443/mzjqpmfcto https://server4:443/oymrzankvu https://server4:443/ajdnrvwwnz https://server4:443/dhutcrbdkg https://server4:443/qwqukuqksn https://server4:443/jidvxrhqfi https://server4:443/qltgglfhbd https://server4:443/thznwhlrpc https://server4:443/zykwfgifjs https://server4:443/ygtinftrtf https://server4:443/mgxotevhoi https://server4:443/lmuhuejetp https://server4:443/lvaagtidcx https://server4:443/ejuqddtvsu https://server4:443/cacslwkfba https://server4:443/bpdnqdjojg https://server4:443/dzobavqcbz https://server4:443/ugittdtqye https://server4:443/gqcrruyctl https://server4:443/hdfcvymxho https://server4:443/xtkgjqmvop https://server4:443/pfurclnalj https://server4:443/nfxvsuehli https://server4:443/nqwwzijuwz https://server4:443/ztwdchcadf https://server4:443/rqgmwbrrir https://server4:443/njlkkgyunr https://server4:443/sdwpmxzrpr
2025-04-30 11:45:47,669 
2025-04-30 11:45:47,669 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_vumyvksv/ TESTCASE_SERVER=multiconnect TESTCASE_CLIENT=multiconnect WWW=/tmp/www_lvxt6un2/ DOWNLOADS=/tmp/download_jnbl69jg/ SERVER_LOGS=/tmp/logs_server_6ldfhkjc CLIENT_LOGS=/tmp/logs_client_6rncz_20 SCENARIO="drop-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/microsoft/msquic/qns:main REQUESTS="https://server4:443/zebjmtpilg https://server4:443/umrjhqlvqd https://server4:443/deiuqtarca https://server4:443/yznmuhknlu https://server4:443/vhjbbvzzfq https://server4:443/gcybssftgj https://server4:443/ahhvifymnj https://server4:443/ulkntklxqx https://server4:443/goowyclqct https://server4:443/ozezvtkuym https://server4:443/jvlmkrdwne https://server4:443/dixfljrjvu https://server4:443/cinqgwmxxy https://server4:443/uamczgjewd https://server4:443/jwnkplhqeg https://server4:443/bqnkcxpcol https://server4:443/yngdomgeck https://server4:443/ftkmquqpda https://server4:443/rsbukwzaot https://server4:443/kgzdkeispi https://server4:443/bckzcifsgy https://server4:443/gbtufujvzj https://server4:443/mzjqpmfcto https://server4:443/oymrzankvu https://server4:443/ajdnrvwwnz https://server4:443/dhutcrbdkg https://server4:443/qwqukuqksn https://server4:443/jidvxrhqfi https://server4:443/qltgglfhbd https://server4:443/thznwhlrpc https://server4:443/zykwfgifjs https://server4:443/ygtinftrtf https://server4:443/mgxotevhoi https://server4:443/lmuhuejetp https://server4:443/lvaagtidcx https://server4:443/ejuqddtvsu https://server4:443/cacslwkfba https://server4:443/bpdnqdjojg https://server4:443/dzobavqcbz https://server4:443/ugittdtqye https://server4:443/gqcrruyctl https://server4:443/hdfcvymxho https://server4:443/xtkgjqmvop https://server4:443/pfurclnalj https://server4:443/nfxvsuehli https://server4:443/nqwwzijuwz https://server4:443/ztwdchcadf https://server4:443/rqgmwbrrir https://server4:443/njlkkgyunr https://server4:443/sdwpmxzrpr"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 11:46:02,405  Container sim  Recreate
 Container sim  Recreated
 Container server  Recreate
 Container client  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-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  | Waiting forever.
server  | 
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
sim     | server:443 is available after 1.023167997s
sim     | Using scenario: drop-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 eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads)
client  | + '[' 'https://server4:443/zebjmtpilg https://server4:443/umrjhqlvqd https://server4:443/deiuqtarca https://server4:443/yznmuhknlu https://server4:443/vhjbbvzzfq https://server4:443/gcybssftgj https://server4:443/ahhvifymnj https://server4:443/ulkntklxqx https://server4:443/goowyclqct https://server4:443/ozezvtkuym https://server4:443/jvlmkrdwne https://server4:443/dixfljrjvu https://server4:443/cinqgwmxxy https://server4:443/uamczgjewd https://server4:443/jwnkplhqeg https://server4:443/bqnkcxpcol https://server4:443/yngdomgeck https://server4:443/ftkmquqpda https://server4:443/rsbukwzaot https://server4:443/kgzdkeispi https://server4:443/bckzcifsgy https://server4:443/gbtufujvzj https://server4:443/mzjqpmfcto https://server4:443/oymrzankvu https://server4:443/ajdnrvwwnz https://server4:443/dhutcrbdkg https://server4:443/qwqukuqksn https://server4:443/jidvxrhqfi https://server4:443/qltgglfhbd https://server4:443/thznwhlrpc https://server4:443/zykwfgifjs https://server4:443/ygtinftrtf https://server4:443/mgxotevhoi https://server4:443/lmuhuejetp https://server4:443/lvaagtidcx https://server4:443/ejuqddtvsu https://server4:443/cacslwkfba https://server4:443/bpdnqdjojg https://server4:443/dzobavqcbz https://server4:443/ugittdtqye https://server4:443/gqcrruyctl https://server4:443/hdfcvymxho https://server4:443/xtkgjqmvop https://server4:443/pfurclnalj https://server4:443/nfxvsuehli https://server4:443/nqwwzijuwz https://server4:443/ztwdchcadf https://server4:443/rqgmwbrrir https://server4:443/njlkkgyunr https://server4:443/sdwpmxzrpr' ']'
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/zebjmtpilg https://server4:443/umrjhqlvqd https://server4:443/deiuqtarca https://server4:443/yznmuhknlu https://server4:443/vhjbbvzzfq https://server4:443/gcybssftgj https://server4:443/ahhvifymnj https://server4:443/ulkntklxqx https://server4:443/goowyclqct https://server4:443/ozezvtkuym https://server4:443/jvlmkrdwne https://server4:443/dixfljrjvu https://server4:443/cinqgwmxxy https://server4:443/uamczgjewd https://server4:443/jwnkplhqeg https://server4:443/bqnkcxpcol https://server4:443/yngdomgeck https://server4:443/ftkmquqpda https://server4:443/rsbukwzaot https://server4:443/kgzdkeispi https://server4:443/bckzcifsgy https://server4:443/gbtufujvzj https://server4:443/mzjqpmfcto https://server4:443/oymrzankvu https://server4:443/ajdnrvwwnz https://server4:443/dhutcrbdkg https://server4:443/qwqukuqksn https://server4:443/jidvxrhqfi https://server4:443/qltgglfhbd https://server4:443/thznwhlrpc https://server4:443/zykwfgifjs https://server4:443/ygtinftrtf https://server4:443/mgxotevhoi https://server4:443/lmuhuejetp https://server4:443/lvaagtidcx https://server4:443/ejuqddtvsu https://server4:443/cacslwkfba https://server4:443/bpdnqdjojg https://server4:443/dzobavqcbz https://server4:443/ugittdtqye https://server4:443/gqcrruyctl https://server4:443/hdfcvymxho https://server4:443/xtkgjqmvop https://server4:443/pfurclnalj https://server4:443/nfxvsuehli https://server4:443/nqwwzijuwz https://server4:443/ztwdchcadf https://server4:443/rqgmwbrrir https://server4:443/njlkkgyunr 'https://server4:443/sdwpmxzrpr
client  | '
client  | ++ tee -i -a /logs/client.log
client  | 0.000 DEBUG Logging initialized
client  | 0.000 DEBUG Default socket send buffer size is 212992
client  | 0.000 DEBUG Default socket receive buffer size is 1048576, not changing
client  | 0.000 INFO hq-interop Client connecting: 0.0.0.0:44078 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=ef39dc266eb783b0
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:44078->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443] Path validated Instant { tv_sec: 544, tv_nsec: 477050001 }
client  | 0.001 DEBUG [Client ef39dc266eb783b0] client_start
client  | 0.001 DEBUG Writing transport parameters, msg=1
client  | 0.001 DEBUG [Agent 0x563f7b26b2d0] state -> InProgress
client  | 0.001 DEBUG [Client ef39dc266eb783b0] State change from Init -> WaitInitial
client  | 0.001 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.001 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.001 DEBUG CRYPTO for in offset=0, len=1213
client  | 0.001 DEBUG [Client ef39dc266eb783b0] pn=0 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1213 }
client  | 0.002 DEBUG packet_sent this=0x563f7b27ebe0, pn=0, ps=1252
client  | 0.002 DEBUG ECN probing: sent 1 probes
client  | 0.002 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1213, len=326
client  | 0.002 DEBUG [Client ef39dc266eb783b0] pn=1 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 366
client  |   TX -> Crypto { offset: 1213, len: 326 }
client  | 0.002 DEBUG [Client ef39dc266eb783b0] pad Initial from 366 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x563f7b27ebe0, pn=1, ps=1252
client  | 0.002 DEBUG ECN probing: sent 2 probes
client  | 0.002 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) 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 ef39dc266eb783b0] delay duration 3.847366ms
client  | 0.002 DEBUG Setting timeout of 3.847366ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) 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 ef39dc266eb783b0] delay duration 3.821679ms
client  | 0.002 DEBUG Setting timeout of 3.821679ms
client  | 0.007 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) 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 ef39dc266eb783b0] delay duration 294.812428ms
client  | 0.007 DEBUG Setting timeout of 294.812428ms
sim     | Forwarding 1252 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 0/1 (0.0%)
sim     | Dropping 1252 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 1/2 (50.0%)
sim     | Forwarding 1260 bytes 193.167.100.100:443 -> 193.167.0.100:44078, dropped 0/1 (0.0%)
client  | 0.065 DEBUG [Client ef39dc266eb783b0] pn=0 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, NotEct) len 1260
client  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 98, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
client  |   -> RX Padding { len: 1213 }
client  | 0.065 DEBUG [Client ef39dc266eb783b0] Rx ACK space=in, ranges=[0..=0]
client  | 0.065 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
client  | 0.065 DEBUG on_packets_acked this=0x563f7b27ebe0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252
client  | 0.065 DEBUG Acked crypto frame space=in offset=0 length=1213
client  | 0.065 DEBUG [Client ef39dc266eb783b0] Changing to use Server CID=ef39dc266eb783b0
client  | 0.065 DEBUG [Client ef39dc266eb783b0] State change from WaitInitial -> WaitVersion
client  | 0.065 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.065 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.065 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.065 DEBUG [Client ef39dc266eb783b0] delay duration 127.687955ms
client  | 0.065 DEBUG Setting timeout of 127.687955ms
client  | 0.065 WARN Unhandled event StateChange(WaitVersion)
client  | 0.065 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.065 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.065 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.065 DEBUG [Client ef39dc266eb783b0] delay duration 127.642621ms
client  | 0.065 DEBUG Setting timeout of 127.642621ms
client  | 0.194 DEBUG [LossRecovery] PTO timer fired for Initial
client  | 0.194 DEBUG [Client ef39dc266eb783b0] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 })
client  | 0.194 INFO Lost crypto frame space=in offset=1213 length=326
client  | 0.194 DEBUG [Client ef39dc266eb783b0] Lost: EcnEct0
client  | 0.194 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false }
client  | 0.194 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.194 DEBUG CRYPTO for in offset=1213, len=326
client  | 0.194 DEBUG [Client ef39dc266eb783b0] pn=2 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 366
client  |   TX -> Crypto { offset: 1213, len: 326 }
client  | 0.194 DEBUG [Client ef39dc266eb783b0] pad Initial from 366 to PLPMTU 1252
client  | 0.194 DEBUG packet_sent this=0x563f7b27ebe0, pn=2, ps=1252
client  | 0.194 DEBUG ECN probing: sent 3 probes
client  | 0.194 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.194 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.195 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.195 DEBUG [Client ef39dc266eb783b0] delay duration 381.762236ms
client  | 0.195 DEBUG Setting timeout of 381.762236ms
sim     | Dropping 1252 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 2/3 (66.7%)
client  | 0.578 DEBUG [LossRecovery] PTO timer fired for Initial
client  | 0.578 DEBUG [Client ef39dc266eb783b0] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 })
client  | 0.578 INFO Lost crypto frame space=in offset=1213 length=326
client  | 0.578 DEBUG [Client ef39dc266eb783b0] Lost: EcnEct0
client  | 0.578 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false }
client  | 0.578 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.578 DEBUG CRYPTO for in offset=1213, len=326
client  | 0.578 DEBUG [Client ef39dc266eb783b0] pn=3 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 366
client  |   TX -> Crypto { offset: 1213, len: 326 }
client  | 0.578 DEBUG [Client ef39dc266eb783b0] pad Initial from 366 to PLPMTU 1252
client  | 0.578 DEBUG packet_sent this=0x563f7b27ebe0, pn=3, ps=1252
client  | 0.578 DEBUG ECN probing: sent 4 probes
client  | 0.578 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.578 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 0.578 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.578 DEBUG [Client ef39dc266eb783b0] delay duration 763.774427ms
client  | 0.578 DEBUG Setting timeout of 763.774427ms
sim     | Dropping 1252 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 3/4 (75.0%)
client  | 1.343 DEBUG [LossRecovery] PTO timer fired for Initial
client  | 1.343 DEBUG [Client ef39dc266eb783b0] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 })
client  | 1.343 INFO Lost crypto frame space=in offset=1213 length=326
client  | 1.343 DEBUG [Client ef39dc266eb783b0] Lost: EcnEct0
client  | 1.343 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false }
client  | 1.343 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.343 DEBUG CRYPTO for in offset=1213, len=326
client  | 1.343 DEBUG [Client ef39dc266eb783b0] pn=4 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 366
client  |   TX -> Crypto { offset: 1213, len: 326 }
client  | 1.343 DEBUG [Client ef39dc266eb783b0] pad Initial from 366 to PLPMTU 1252
client  | 1.343 DEBUG packet_sent this=0x563f7b27ebe0, pn=4, ps=1252
client  | 1.343 DEBUG ECN probing: sent 5 probes
client  | 1.343 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.343 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.343 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.343 DEBUG [Client ef39dc266eb783b0] delay duration 1.527757132s
client  | 1.343 DEBUG Setting timeout of 1.527757132s
sim     | Forwarding 1252 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 3/5 (60.0%)
sim     | Dropping 1220 bytes 193.167.100.100:443 -> 193.167.0.100:44078, dropped 1/2 (50.0%)
sim     | Forwarding 1220 bytes 193.167.100.100:443 -> 193.167.0.100:44078, dropped 1/3 (33.3%)
client  | 1.527 DEBUG [Client ef39dc266eb783b0] pn=3 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, NotEct) len 133
client  |   -> RX Crypto { offset: 0, len: 90 }
client  | 1.527 DEBUG Read Ok(90) bytes
client  | 1.528 DEBUG Write secret available for Handshake: SymKey [48]: 13fc215d6852fe277b099e75dbb5432123386633078fdc29fe1cefb4dd3ae8ac2f90323e7b3e5947e26b1d19b2028838
client  | 1.528 DEBUG Read secret available for Handshake: SymKey [48]: 7e3c42ddf7dd22b60125bc3b42fdf212bd5d52c8855a430237b468302c36e9f5708c03da4702c4d17031d46ba9c0a461
client  | 1.528 DEBUG [Agent 0x563f7b26b2d0] state -> InProgress
client  | 1.528 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4866
client  | 1.528 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4866
client  | 1.528 DEBUG [Crypto] Handshake keys installed
client  | 1.528 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 546, tv_nsec: 3925044 }
client  | 1.528 DEBUG [Client ef39dc266eb783b0] State change from WaitVersion -> Handshaking
client  | 1.528 DEBUG [Client ef39dc266eb783b0] pn=4 type=Handshake pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, NotEct) len 1087
client  |   -> RX Crypto { offset: 0, len: 732 }
client  |   -> RX Padding { len: 313 }
client  | 1.528 DEBUG Read Ok(732) bytes
client  | 1.529 DEBUG [Agent 0x563f7b26b2d0] state -> AuthenticationPending
client  | 1.529 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 546, tv_nsec: 3925044 }
client  | 1.529 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.529 DEBUG Building Initial dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.529 DEBUG [Client ef39dc266eb783b0] pn=5 type=Initial pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 43
client  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 171, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 0 }], ecn_count: None }
client  | 1.529 DEBUG Building Handshake dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.529 DEBUG [Client ef39dc266eb783b0] pn=0 type=Handshake pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 83
client  |   TX -> Ack { largest_acknowledged: 4, ack_delay: 171, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 1.529 DEBUG [Client ef39dc266eb783b0] Drop packet number space in
client  | 1.529 DEBUG [LossRecovery] Reset loss recovery state for Initial
client  | 1.529 WARN [LossRecovery] ignoring in-5 from dropped space
client  | 1.529 DEBUG ECN probing: sent 6 probes
client  | 1.529 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.529 DEBUG Building Handshake dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.529 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.529 DEBUG [Client ef39dc266eb783b0] delay duration 190.864482ms
client  | 1.529 DEBUG Setting timeout of 190.864482ms
client  | 1.529 DEBUG StateChange(Handshaking)
client  | 1.529 WARN Cannot create stream ConnectionState
client  | 1.529 DEBUG [Client ef39dc266eb783b0] Authenticated Ok
client  | 1.529 DEBUG Write secret available for ApplicationData: SymKey [48]: 094ec278d746d3e19741a315f314962a27166f5264ed723d66845ef2c6c5c87e226d2cce3028150b3328ea452f0b8636
client  | 1.529 DEBUG Read secret available for ApplicationData: SymKey [48]: 3466bf3087256da3cf92c3fc80f301f8e6f0ee9562fa36b26821244f1a8a92e355d06c78b16eb5309dc219a4af53ee16
client  | 1.529 DEBUG [Agent 0x563f7b26b2d0] SSL_AuthCertificateComplete: Ok(())
client  | 1.529 DEBUG [Agent 0x563f7b26b2d0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4866, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 1.529 DEBUG [Client ef39dc266eb783b0] TLS connection complete
client  | 1.529 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4866
client  | 1.529 DEBUG [Crypto] Application write key installed
client  | 1.529 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4866
client  | 1.529 DEBUG [Crypto] application read keys installed
client  | 1.529 WARN [Client ef39dc266eb783b0] ISCID test failed: self cid Some(CID [8]: ef39dc266eb783b0) != tp cid Some("839d79e7286946eb75")
client  | 1.529 DEBUG [Client ef39dc266eb783b0] State change from Handshaking -> Closing { error: Transport(ProtocolViolation), timeout: Instant { tv_sec: 546, tv_nsec: 578445649 } }
client  | 1.529 WARN Unhandled event StateChange(Closing { error: Transport(ProtocolViolation), timeout: Instant { tv_sec: 546, tv_nsec: 578445649 } })
client  | 1.529 DEBUG [Client ef39dc266eb783b0] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.529 DEBUG Building Handshake dcid Some(CID [8]: ef39dc266eb783b0) scid Some(CID [0]: )
client  | 1.529 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 546, tv_nsec: 5809855 }
client  | 1.529 DEBUG [Client ef39dc266eb783b0] pn=1 type=Handshake pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 44
client  |   TX -> Ack { largest_acknowledged: 4, ack_delay: 235, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(10), frame_type: 0, reason_phrase: "" }
client  | 1.529 DEBUG Building Short dcid Some(CID [8]: ef39dc266eb783b0)
client  | 1.529 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 546, tv_nsec: 5809855 }
client  | 1.529 DEBUG [Client ef39dc266eb783b0] pn=0 type=Short pri-path:ef39dc266eb783b0 0.0.0.0:44078->193.167.100.100:443 IpTos(Cs0, Ect0) len 74
client  |   TX -> ConnectionClose { error_code: Transport(10), frame_type: 0, reason_phrase: "" }
client  | 1.529 DEBUG ECN probing: sent 7 probes
client  | 1.529 DEBUG Setting timeout of 572.556116ms
client  | Error: TransportError(ProtocolViolation)
sim     | Forwarding 83 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 3/6 (50.0%)
sim     | Forwarding 74 bytes 193.167.0.100:44078 -> 193.167.100.100:443, dropped 3/7 (42.9%)
sim     | Forwarding 75 bytes 193.167.100.100:443 -> 193.167.0.100:44078, dropped 1/4 (25.0%)

client exited with code 1
Aborting on container exit...
 Container client  Stopping
 Container server  Stopping
 Container client  Stopped
 Container server  Stopped
 Container sim  Stopping
 Container sim  Stopped