2025-09-12 05:10:18,972 Generated random file: bkbbpgnveb of size: 5120
2025-09-12 05:10:18,972 Generated random file: vyxlrsxdoh of size: 10240
2025-09-12 05:10:18,972 Requests: https://server6:443/bkbbpgnveb https://server6:443/vyxlrsxdoh
2025-09-12 05:10:19,037 
2025-09-12 05:10:19,038 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_67l3d5_u/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_q1opj446/ DOWNLOADS=/tmp/download_nx3178uy/ SERVER_LOGS=/tmp/logs_server__t4_0zby CLIENT_LOGS=/tmp/logs_client_q1hrotjp SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/alibaba/xquic/xquic-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/bkbbpgnveb https://server6:443/vyxlrsxdoh"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-09-12 05:10:31,900  Container sim  Recreate
 Container sim  Recreated
 Container client  Recreate
 Container server  Recreate
 Container client  Recreated
 Container server  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
client  | tx-tcp-ecn-segmentation: off [not requested]
client  | tx-tcp-mangleid-segmentation: off [not requested]
client  | tx-tcp6-segmentation: off [not requested]
client  | tx-udp-segmentation: off [not requested]
client  | tx-checksum-sctp: off
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
server  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + '[' -n transfer ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.dtmSRDnz4R
server  | + mkdir -p /neqo/db
server  | + certutil -N -d sql:/neqo/db --empty-password
server  | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.dtmSRDnz4R
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.dtmSRDnz4R -W ''
server  | pk12util: PKCS12 IMPORT SUCCESSFUL
server  | + certutil -L -d sql:/neqo/db -n cert
server  | Certificate:
server  |     Data:
server  |         Version: 3 (0x2)
server  |         Serial Number:
server  |             2e:34:0a:53:14:25:2c:a6:c5:65:cf:6c:1b:41:ed:3d:
server  |             2c:21:15:68
server  |         Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |         Issuer: "O=interop runner Root Certificate Authority"
server  |         Validity:
server  |             Not Before: Fri Sep 12 05:10:19 2025
server  |             Not After : Mon Sep 22 05:10:19 2025
server  |         Subject: "O=interop runner leaf"
server  |         Subject Public Key Info:
server  |             Public Key Algorithm: X9.62 elliptic curve public key
server  |                 Args:
server  |                     06:08:2a:86:48:ce:3d:03:01:07
server  |             EC Public Key:
server  |                 PublicValue:
server  |                     04:64:3a:3b:82:89:60:b2:91:de:3b:04:5b:83:61:1a:
server  |                     6f:34:63:7f:d7:b2:2d:24:90:00:66:89:6c:c7:e2:7c:
server  |                     a0:cc:06:55:96:67:d6:76:f3:cf:97:c0:10:ff:a4:b0:
server  |                     06:ba:35:f2:5c:60:73:94:1b:e2:f6:db:9b:da:b3:29:
server  |                     e4
server  |                 Curve: ANSI X9.62 elliptic curve prime256v1 (aka secp256r1, NIST P-256)
server  |         Signed Extensions:
server  |             Name: Certificate Subject Alt Name
server  |             DNS name: "server"
server  |             DNS name: "server4"
server  |             DNS name: "server6"
server  |             DNS name: "server46"
server  | 
server  |             Name: Certificate Subject Key ID
server  |             Data:
server  |                 4b:fb:c6:92:6b:22:43:83:d2:e3:a6:46:fc:f8:2b:85:
server  |                 33:32:4c:a1
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 cb:7b:92:19:88:bd:b0:c5:3e:5b:9f:88:0f:46:bf:07:
server  |                 11:73:42:9b
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:21:00:ee:a5:2c:41:7e:65:21:5e:8a:3c:ac:
server  |         d7:bd:b7:dc:5e:7d:d9:e3:d6:af:ee:1c:6c:f9:0f:0f:
server  |         6e:72:dd:d2:84:02:20:7b:7a:d2:aa:4c:e2:a4:3c:b2:
server  |         69:b9:40:bb:d2:ac:3d:db:74:7b:db:b4:28:5e:9b:dd:
server  |         de:38:9d:ec:6e:4e:93
server  |     Fingerprint (SHA-256):
server  |         B9:3F:78:BC:96:38:91:B6:FA:79:BD:C9:60:AE:39:47:12:CA:A9:8F:8D:9A:2E:DF:13:FC:A5:9E:89:80:DF:B9
server  |     Fingerprint (SHA1):
server  |         57:18:51:48:C2:B8:C8:AE:FD:20:AD:3A:EF:9E:DA:2F:B9:A7:B1:C3
server  | 
server  |     Mozilla-CA-Policy: false (attribute missing)
server  |     Certificate Trust Flags:
server  |         SSL Flags:
server  |             User
server  |         Email Flags:
server  |             User
server  |         Object Signing Flags:
server  |             User
server  | 
server  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT")
server  | + '[' transfer = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443'
server  | ++ tee -i -a /logs/server.log
server  | 0.000 DEBUG Logging initialized
server  | 0.003 DEBUG Default socket send buffer size is Ok(212992)
server  | 0.003 DEBUG Default socket receive buffer size is 1048576, not changing
server  | 0.003 INFO Server waiting for connection on: Ok([::]:443)
server  | 0.278 DEBUG [Server] Unsupported version: 57414954
server  | 0.278 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:46191 Tos(Cs0, NotEct) len 15
sim     | server:443 is available after 501.837049ms
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | ./demo_client -l d  -L /logs/client.log -D /downloads -k /logs/keys.log -K 30 -o -U "https://server6:443/bkbbpgnveb https://server6:443/vyxlrsxdoh"
client  | 
client  | option log level :d
client  | option log directory :/logs/client.log
client  | option save body dir: /downloads
client  | key output file: /logs/keys.log
client  | client life circle time: 30
client  | set interop mode
client  | option url only:https://server6:443/bkbbpgnveb https://server6:443/vyxlrsxdoh
client  | server[server6] addr: fd00:cafe:cafe:100::100:443.
client  | No.0 path created id = 0
client  | open file[/downloads/bkbbpgnveb] suc
client  | open file[/downloads/vyxlrsxdoh] suc
server  | 0.995 DEBUG [Server] Handle initial
server  | 0.995 INFO AddressValidation: no token; accepting
server  | 0.995 INFO [Server] Accept connection CID [8]: c72197c43fb6b7c5
server  | 0.995 DEBUG Overwrite initial version Version1 ==> Version1
server  | 0.997 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500
server  | 0.997 INFO [Server ...] Received valid Initial packet with scid CID [8]: ac8648e042cd34b2 dcid CID [8]: c72197c43fb6b7c5
server  | 0.997 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=c72197c43fb6b7c5
server  | 0.997 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=11
server  | 0.997 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 0.997 DEBUG [Server c72197c43fb6b7c5] State change from Init -> WaitInitial
server  | 0.997 DEBUG [Server c72197c43fb6b7c5] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1200
server  |   -> RX Crypto { offset: 0, len: 305 }
server  |   -> RX Padding { len: 845 }
server  | 0.997 DEBUG 0-RTT: no token, no 0-RTT
server  | 0.998 DEBUG Read secret available for Handshake: SymKey [32]: fcf6aa78dabed5b8b71995429384fe55c343ef0576151a26e92191a633c3d8db
server  | 0.998 DEBUG Write secret available for Handshake: SymKey [32]: d4b0b069462fc6993ccc3bbdef8cbc30071a866975404a4ea676325ba38a591c
server  | 0.998 DEBUG Writing transport parameters, msg=8
server  | 0.998 DEBUG Read secret available for ApplicationData: SymKey [32]: bdf0e5095493c6a056b798f804ccbee2166659e788a9922606e452231ba17d39
server  | 0.998 DEBUG Write secret available for ApplicationData: SymKey [32]: a61deef5ad3490f1f7e2cbfe67c25f9bdb716ad5cde9383b097b2bd4ad61fecc
server  | 0.998 DEBUG [Agent 0x556eb2296650] state -> InProgress
server  | 0.998 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 0.998 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 0.998 DEBUG [Crypto] Handshake keys installed
server  | 0.998 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 0.998 DEBUG [Crypto] Application write key installed
server  | 0.998 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 494597981 }
server  | 0.998 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:52370] Make permanent
server  | 0.998 DEBUG [unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370] set as primary path
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] State change from WaitInitial -> Handshaking
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.998 DEBUG Building Initial dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG CRYPTO for in offset=0, len=123
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] pn=11 type=Initial pri-unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 177
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   TX -> Crypto { offset: 0, len: 123 }
server  | 0.998 DEBUG Building Handshake dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG CRYPTO for hs offset=0, len=726
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] pn=0 type=Handshake pri-unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 951
server  |   TX -> Crypto { offset: 0, len: 726 }
server  | 0.998 DEBUG packet_sent this=0x556eb22966d0, pn=0, ps=774
server  | 0.998 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] pad Initial from 951 to PLPMTU 1232
server  | 0.998 DEBUG packet_sent this=0x556eb22966d0, pn=11, ps=458
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.998 DEBUG Building Initial dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG Building Handshake dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 0.998 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] delay duration 296.486871ms
server  | 0.998 DEBUG Setting timeout of 296.486871ms
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.998 DEBUG Building Initial dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG Building Handshake dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 0.998 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 0.998 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.998 DEBUG [Server c72197c43fb6b7c5] delay duration 296.446896ms
server  | 0.998 DEBUG Setting timeout of 296.446896ms
server  | 1.032 DEBUG [Server c72197c43fb6b7c5] Drop packet number space in
server  | 1.032 DEBUG [recovery::Loss] Reset loss recovery state for Initial
server  | 1.032 INFO [pri-unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370] discarding a packet without an RTT estimate; guessing RTT=37.33335ms
server  | 1.032 DEBUG [Server c72197c43fb6b7c5] pn=0 type=Handshake pri-unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 86
server  |   -> RX Crypto { offset: 0, len: 36 }
server  | 1.032 DEBUG [Agent 0x556eb2296650] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 23, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
server  | 1.032 DEBUG [Server c72197c43fb6b7c5] TLS connection complete
server  | 1.032 DEBUG [pri-unv-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370] Path validated Instant { tv_sec: 802, tv_nsec: 531931331 }
server  | 1.032 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
server  | 1.033 DEBUG [Crypto] application read keys installed
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] State change from Handshaking -> Connected
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] State change from Connected -> Confirmed
server  | 1.033 DEBUG PMTUD started with probe size 1380
server  | 1.033 INFO [Server c72197c43fb6b7c5] Connection established
server  | 1.033 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 531931331 }
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.033 DEBUG Building Handshake dcid Some(CID [8]: ac8648e042cd34b2) scid Some(CID [10]: aad33d4c4cca84f3dcde)
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] pn=1 type=Handshake pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 49
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] Drop packet number space hs
server  | 1.033 DEBUG [recovery::Loss] Reset loss recovery state for Handshake
server  | 1.033 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] pn=0 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [123, 11, 114, 234, 116, 221, 80, 173, 104, 41], stateless_reset_token: [203, 127, 17, 156, 35, 198, 66, 214, 159, 133, 81, 177, 113, 11, 228, 240] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [193, 235, 125, 91, 186, 133, 209, 59, 131, 8], stateless_reset_token: [230, 112, 148, 59, 128, 240, 226, 15, 247, 24, 57, 135, 221, 130, 247, 225] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [36, 121, 2, 223, 71, 246, 40, 173, 32, 108], stateless_reset_token: [181, 33, 225, 128, 205, 188, 80, 196, 227, 74, 80, 3, 4, 241, 213, 182] }
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [187, 207, 87, 149, 185, 69, 97, 117, 149, 8], stateless_reset_token: [5, 208, 141, 87, 116, 44, 12, 254, 222, 124, 227, 207, 11, 19, 7, 116] }
server  |   TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [83, 155, 104, 87, 157, 98, 4, 185, 121, 163], stateless_reset_token: [44, 132, 250, 5, 47, 159, 131, 227, 33, 28, 15, 198, 101, 253, 170, 156] }
server  |   TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [56, 84, 145, 152, 140, 212, 135, 162, 240, 154], stateless_reset_token: [42, 60, 176, 101, 232, 48, 220, 215, 147, 195, 165, 162, 96, 113, 193, 108] }
server  |   TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [69, 185, 36, 70, 226, 18, 11, 59, 39, 126], stateless_reset_token: [166, 95, 27, 232, 104, 1, 76, 88, 101, 121, 71, 12, 45, 26, 95, 151] }
server  |   TX -> Padding { len: 1046 }
server  | 1.033 DEBUG packet_sent this=0x556eb22966d0, pn=0, ps=1283
server  | 1.033 DEBUG ECN probing: sent 1 probes
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.033 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.033 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] pn=1 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1305 }
server  | 1.033 DEBUG packet_sent this=0x556eb22966d0, pn=1, ps=1332
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.033 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.033 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.033 DEBUG ECN probing: sent 2 probes
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.033 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.033 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.033 DEBUG [Server c72197c43fb6b7c5] delay duration 1.474ms
server  | 1.033 DEBUG Setting timeout of 1.474ms
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] send session ticket 40640008c72197c43fb6b7c50104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0aaad33d4c4cca84f3dcde110c00000001cababafa000000016ab200c0000000ff02de1a0243e8200244b0686921
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 409.717µs
server  | 1.034 DEBUG Setting timeout of 409.717µs
server  | 1.034 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 1
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 376.885µs
server  | 1.034 DEBUG Setting timeout of 376.885µs
server  | 1.034 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 2
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 351.007µs
server  | 1.034 DEBUG Setting timeout of 351.007µs
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] pn=0 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 52
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  | 1.034 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 553697078 }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 330.258µs
server  | 1.034 DEBUG Setting timeout of 330.258µs
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] pn=1 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 52
server  |   -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true }
server  | 1.034 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 533740008 }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] pn=2 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 31
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None }
server  | 1.034 DEBUG ECN probing: sent 3 probes
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG CRYPTO for ap offset=0, len=305
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] pn=3 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 380
server  |   TX -> Crypto { offset: 0, len: 305 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 84, 195, 115, 249, 4, 98, 228, 30, 27, 2, 73, 214, 125, 202, 248, 244, 204, 30, 84, 92, 197, 140, 2, 150, 199, 85, 153, 245, 132, 84, 13, 37, 203, 156, 78, 0] }
server  | 1.034 DEBUG packet_sent this=0x556eb22966d0, pn=3, ps=380
server  | 1.034 DEBUG ECN probing: sent 4 probes
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 136.943674ms
server  | 1.034 DEBUG Setting timeout of 136.943674ms
server  | 1.034 DEBUG Path = 'bkbbpgnveb'
server  | 1.034 DEBUG Path = 'vyxlrsxdoh'
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] pn=4 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false }
server  | 1.034 DEBUG packet_sent this=0x556eb22966d0, pn=4, ps=1232
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG ECN probing: sent 5 probes
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server c72197c43fb6b7c5] delay duration 1.790074ms
server  | 1.034 DEBUG Setting timeout of 1.790074ms
server  | 1.036 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.036 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.036 DEBUG [Server c72197c43fb6b7c5] pn=5 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false }
server  | 1.036 DEBUG packet_sent this=0x556eb22966d0, pn=5, ps=1232
server  | 1.036 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG ECN probing: sent 6 probes
server  | 1.036 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.037 DEBUG [Server c72197c43fb6b7c5] delay duration 1.524503ms
server  | 1.037 DEBUG Setting timeout of 1.524503ms
server  | 1.037 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.037 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.037 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.037 DEBUG [Server c72197c43fb6b7c5] delay duration 1.498735ms
server  | 1.037 DEBUG Setting timeout of 1.498735ms
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.039 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] pn=6 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false }
server  | 1.039 DEBUG packet_sent this=0x556eb22966d0, pn=6, ps=1232
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG ECN probing: sent 7 probes
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] delay duration 1.208989ms
server  | 1.039 DEBUG Setting timeout of 1.208989ms
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG [Server c72197c43fb6b7c5] delay duration 1.185045ms
server  | 1.039 DEBUG Setting timeout of 1.185045ms
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] pn=7 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false }
server  | 1.041 DEBUG packet_sent this=0x556eb22966d0, pn=7, ps=1232
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] pn=8 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4810, len: 310, fin: true }
server  |   TX -> Stream { stream_id: 4, offset: 0, len: >>888, fin: false }
server  | 1.041 DEBUG packet_sent this=0x556eb22966d0, pn=8, ps=1232
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG ECN probing: sent 9 probes
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] delay duration 1.69561ms
server  | 1.041 DEBUG Setting timeout of 1.69561ms
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.041 DEBUG [Server c72197c43fb6b7c5] delay duration 1.667757ms
server  | 1.041 DEBUG Setting timeout of 1.667757ms
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] pn=9 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 888, len: >>1202, fin: false }
server  | 1.044 DEBUG packet_sent this=0x556eb22966d0, pn=9, ps=1232
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] pn=10 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 2090, len: >>1202, fin: false }
server  | 1.044 DEBUG packet_sent this=0x556eb22966d0, pn=10, ps=1232
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 701, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] pn=11 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, Ect0) len 701
server  |   TX -> Stream { stream_id: 4, offset: 3292, len: >>671, fin: false }
server  | 1.044 DEBUG packet_sent this=0x556eb22966d0, pn=11, ps=701
server  | 1.044 DEBUG ECN probing: sent 12 probes
server  | 1.044 DEBUG ECN probing concluded with 12 probes sent
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.044 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] delay duration 136.830683ms
server  | 1.044 DEBUG Setting timeout of 136.830683ms
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.044 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG [Server c72197c43fb6b7c5] delay duration 136.801368ms
server  | 1.044 DEBUG Setting timeout of 136.801368ms
client  | >>>>>>>> request time cost:86394 us, speed:59 K/s 
client  | >>>>>>>> user_stream[0x561bf6260300], req: /bkbbpgnveb, send_body_size:11, recv_body_size:5120 
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] pn=2 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 59
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [179, 111, 216, 93, 196, 178, 169, 66], stateless_reset_token: [195, 207, 111, 42, 156, 114, 57, 232, 156, 1, 218, 146, 69, 201, 140, 55] }
server  | 1.065 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 584490318 }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] delay duration 20ms
server  | 1.065 DEBUG Setting timeout of 20ms
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] pn=5 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 59
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [6, 99, 28, 94, 11, 226, 174, 11], stateless_reset_token: [99, 48, 176, 134, 140, 46, 134, 97, 11, 78, 6, 158, 27, 247, 197, 119] }
server  | 1.065 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 802, tv_nsec: 564549589 }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] pn=12 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 33
server  |   TX -> Ack { largest_acknowledged: 5, ack_delay: 0, first_ack_range: 0, ack_ranges: [AckRange { gap: 1, range: 2 }], ecn_count: None }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] delay duration 116.10261ms
server  | 1.065 DEBUG Setting timeout of 116.10261ms
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] delay duration 116.025476ms
server  | 1.065 DEBUG Setting timeout of 116.025476ms
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] pn=6 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 36
server  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 13, first_ack_range: 1, ack_ranges: [], ecn_count: None }
server  | 1.065 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[0..=1]
server  | 1.066 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1
server  | 1.066 WARN ECN validation failed, no ECN counts in ACK frame
server  | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] slow start += 2615
server  | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9705/14935 ssthresh 18446744073709551615] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=9705, cwnd=14935, state=SlowStart, new_acked=2615
server  | 1.066 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.066 DEBUG PMTUD started with probe size 1420
server  | 1.066 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.066 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] pn=13 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1372
server  |   TX -> Ping
server  |   TX -> Stream { stream_id: 4, offset: 3963, len: >>1341, fin: false }
server  | 1.066 DEBUG packet_sent this=0x556eb22966d0, pn=13, ps=1372
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] pn=14 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 5304, len: >>1302, fin: false }
server  | 1.066 DEBUG packet_sent this=0x556eb22966d0, pn=14, ps=1332
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] delay duration 1.110546ms
server  | 1.066 DEBUG Setting timeout of 1.110546ms
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.066 DEBUG [Server c72197c43fb6b7c5] delay duration 1.079739ms
server  | 1.066 DEBUG Setting timeout of 1.079739ms
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] pn=7 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 17, first_ack_range: 1, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=4, 0..=1]
server  | 1.067 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=4
server  | 1.067 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10797/16547 ssthresh 18446744073709551615] slow start += 1612
server  | 1.067 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 10797/16547 ssthresh 18446744073709551615] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=10797, cwnd=16547, state=SlowStart, new_acked=1612
server  | 1.067 DEBUG Acked crypto frame space=ap offset=0 length=305
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.067 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] pn=15 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 6606, len: >>1302, fin: false }
server  | 1.067 DEBUG packet_sent this=0x556eb22966d0, pn=15, ps=1332
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] delay duration 1.087814ms
server  | 1.067 DEBUG Setting timeout of 1.087814ms
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.067 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.067 DEBUG [Server c72197c43fb6b7c5] delay duration 1.069079ms
server  | 1.067 DEBUG Setting timeout of 1.069079ms
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.069 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] pn=16 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 7908, len: >>1302, fin: false }
server  | 1.069 DEBUG packet_sent this=0x556eb22966d0, pn=16, ps=1332
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.069 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] pn=17 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1062
server  |   TX -> Stream { stream_id: 4, offset: 9210, len: 1030, fin: true }
server  | 1.069 DEBUG packet_sent this=0x556eb22966d0, pn=17, ps=1062
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.069 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] delay duration 1.375767ms
server  | 1.069 DEBUG Setting timeout of 1.375767ms
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.069 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.069 DEBUG [Server c72197c43fb6b7c5] delay duration 1.351832ms
server  | 1.069 DEBUG Setting timeout of 1.351832ms
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] pn=8 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 6, ack_delay: 15, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=6, 0..=1]
server  | 1.070 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=6
server  | 1.070 INFO [Cubic [last_max_cwnd: 16547, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 14523/11582 ssthresh 11582] Cong event -> recovery; cwnd 11582, ssthresh 11582
server  | 1.070 DEBUG [Cubic [last_max_cwnd: 16547, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 14523/11582 ssthresh 11582] state -> RecoveryStart
server  | 1.070 DEBUG on_packets_lost this=0x556eb22966d0, bytes_in_flight=14523, cwnd=11582, state=RecoveryStart
server  | 1.070 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 12059/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=12059, cwnd=11582, state=RecoveryStart, new_acked=0
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] Lost: Ack(AckToken { space: ApplicationData, ranges: [PacketRange { largest: 1, smallest: 0, ack_needed: true }] })
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] Lost: EcnEct0
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: Some(Initial), probe: EnumSet(Initial | Handshake | ApplicationData), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] pn=18 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 27
server  |   TX -> Ping
server  | 1.070 DEBUG packet_sent this=0x556eb22966d0, pn=18, ps=29
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] delay duration 102.392305ms
server  | 1.070 DEBUG Setting timeout of 102.392305ms
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG [Server c72197c43fb6b7c5] delay duration 102.348834ms
server  | 1.070 DEBUG Setting timeout of 102.348834ms
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] pn=9 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 8, ack_delay: 25, first_ack_range: 5, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=8, 0..=1]
server  | 1.074 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=8
server  | 1.074 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 9624/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=9624, cwnd=11582, state=Recovery, new_acked=0
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] pn=19 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 28
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.074 DEBUG packet_sent this=0x556eb22966d0, pn=19, ps=29
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] delay duration 94.61778ms
server  | 1.074 DEBUG Setting timeout of 94.61778ms
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG [Server c72197c43fb6b7c5] delay duration 94.586521ms
server  | 1.074 DEBUG Setting timeout of 94.586521ms
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] pn=10 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 10, ack_delay: 15, first_ack_range: 7, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=10, 0..=1]
server  | 1.077 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=10
server  | 1.077 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 7189/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=7189, cwnd=11582, state=Recovery, new_acked=0
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.077 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.077 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] delay duration 85.103659ms
server  | 1.077 DEBUG Setting timeout of 85.103659ms
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.077 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.077 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.077 DEBUG [Server c72197c43fb6b7c5] delay duration 85.046091ms
server  | 1.077 DEBUG Setting timeout of 85.046091ms
client  | >>>>>>>> request time cost:117046 us, speed:87 K/s 
client  | >>>>>>>> user_stream[0x561bf62613a0], req: /vyxlrsxdoh, send_body_size:11, recv_body_size:10240 
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] pn=11 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 13, ack_delay: 18, first_ack_range: 10, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=13, 0..=1]
server  | 1.097 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=13
server  | 1.097 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 5116/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=5116, cwnd=11582, state=Recovery, new_acked=0
server  | 1.097 DEBUG PMTUD probe of size 1420 succeeded
server  | 1.097 DEBUG PMTUD started with probe size 1470
server  | 1.097 DEBUG PLPMTU changed from 1332 to 1372, updating pacer
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.097 DEBUG Sending PMTUD probe of size 1470, count 1
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] pn=20 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1422
server  |   TX -> Ping
server  |   TX -> Padding { len: 1395 }
server  | 1.097 DEBUG packet_sent this=0x556eb22966d0, pn=20, ps=1422
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] delay duration 83.995168ms
server  | 1.097 DEBUG Setting timeout of 83.995168ms
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.097 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.097 DEBUG [Server c72197c43fb6b7c5] delay duration 83.966054ms
server  | 1.098 DEBUG Setting timeout of 83.966054ms
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] pn=12 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 38
server  |   -> RX Ack { largest_acknowledged: 15, ack_delay: 15, first_ack_range: 12, ack_ranges: [AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[3..=15, 0..=1]
server  | 1.100 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=15
server  | 1.100 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 3874/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=3874, cwnd=11582, state=Recovery, new_acked=0
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.100 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] delay duration 77.593713ms
server  | 1.100 DEBUG Setting timeout of 77.593713ms
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.100 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG [Server c72197c43fb6b7c5] delay duration 77.537036ms
server  | 1.100 DEBUG Setting timeout of 77.537036ms
server  | 1.104 DEBUG [Server c72197c43fb6b7c5] pn=13 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 40
server  |   -> RX Ack { largest_acknowledged: 19, ack_delay: 16, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 14 }, AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.104 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[19..=19, 3..=17, 0..=1]
server  | 1.104 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=19
server  | 1.104 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 3845/11582 ssthresh 11582] state -> CongestionAvoidance
server  | 1.104 DEBUG [Cubic [last_max_cwnd: 16547, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: Some(Instant { tv_sec: 802, tv_nsec: 569873599 })] CongCtrl 1451/11582 ssthresh 11582] on_packets_acked this=0x556eb22966d0, limited=0, bytes_in_flight=1451, cwnd=11582, state=CongestionAvoidance, new_acked=29
server  | 1.104 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.104 DEBUG [Server c72197c43fb6b7c5] pn=21 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 28
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 18 }
server  | 1.104 DEBUG packet_sent this=0x556eb22966d0, pn=21, ps=29
server  | 1.104 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server c72197c43fb6b7c5] delay duration 3.764254ms
server  | 1.105 DEBUG Setting timeout of 3.764254ms
server  | 1.105 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server c72197c43fb6b7c5] delay duration 3.733928ms
server  | 1.105 DEBUG Setting timeout of 3.733928ms
server  | 1.109 DEBUG packet_lost this=0x556eb22966d0, pn=18, ps=29
server  | 1.109 INFO [Cubic [last_max_cwnd: 9844.699999999999, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: None] CongCtrl 1451/8107 ssthresh 8107] Cong event -> recovery; cwnd 8107, ssthresh 8107
server  | 1.109 DEBUG [Cubic [last_max_cwnd: 9844.699999999999, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: None] CongCtrl 1451/8107 ssthresh 8107] state -> RecoveryStart
server  | 1.109 DEBUG on_packets_lost this=0x556eb22966d0, bytes_in_flight=1451, cwnd=8107, state=RecoveryStart
server  | 1.109 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.109 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG [Server c72197c43fb6b7c5] delay duration 73.43801ms
server  | 1.109 DEBUG Setting timeout of 73.43801ms
server  | 1.109 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.109 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.109 DEBUG [Server c72197c43fb6b7c5] delay duration 73.398256ms
server  | 1.109 DEBUG Setting timeout of 73.398256ms
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] pn=14 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 40
server  |   -> RX Ack { largest_acknowledged: 21, ack_delay: 16, first_ack_range: 2, ack_ranges: [AckRange { gap: 0, range: 14 }, AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[19..=21, 3..=17, 0..=1]
server  | 1.135 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=21
server  | 1.135 DEBUG on_packets_acked this=0x556eb22966d0, limited=1, bytes_in_flight=0, cwnd=8107, state=RecoveryStart, new_acked=0
server  | 1.135 DEBUG PMTUD probe of size 1470 succeeded
server  | 1.135 DEBUG PMTUD started with probe size 1500
server  | 1.135 DEBUG PLPMTU changed from 1372 to 1422, updating pacer
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.135 DEBUG Sending PMTUD probe of size 1500, count 1
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] pn=22 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 1452
server  |   TX -> Ping
server  |   TX -> Padding { len: 1425 }
server  | 1.135 DEBUG packet_sent this=0x556eb22966d0, pn=22, ps=1452
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.135 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.135 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] delay duration 75.627406ms
server  | 1.135 DEBUG Setting timeout of 75.627406ms
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.135 DEBUG TX blocked, profile=SendProfile { limit: 1422, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG [Server c72197c43fb6b7c5] delay duration 75.602699ms
server  | 1.135 DEBUG Setting timeout of 75.602699ms
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] pn=15 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 41
server  |   -> RX Ack { largest_acknowledged: 22, ack_delay: 3217, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 14 }, AckRange { gap: 0, range: 1 }], ecn_count: None }
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] Rx ACK space=ap, ranges=[19..=22, 3..=17, 0..=1]
server  | 1.193 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=22
server  | 1.193 DEBUG [Cubic [last_max_cwnd: 9844.699999999999, k: 2.1043517990101672, w_max: 16547, ca_epoch_start: None] CongCtrl 0/8107 ssthresh 8107] state -> CongestionAvoidance
server  | 1.193 DEBUG on_packets_acked this=0x556eb22966d0, limited=1, bytes_in_flight=0, cwnd=8107, state=CongestionAvoidance, new_acked=1452
server  | 1.193 DEBUG PMTUD probe of size 1500 succeeded
server  | 1.193 INFO PMTUD stopped, PLPMTU is now 1500, raise timer Some(Instant { tv_sec: 1402, tv_nsec: 692373331 })
server  | 1.193 DEBUG PLPMTU changed from 1422 to 1452, updating pacer
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false }
server  | 1.193 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.193 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false }
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] delay duration 30s
server  | 1.193 DEBUG Setting timeout of 30s
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false }
server  | 1.193 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.193 DEBUG TX blocked, profile=SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false }
server  | 1.193 DEBUG [Server c72197c43fb6b7c5] delay duration 29.999855068s
server  | 1.193 DEBUG Setting timeout of 29.999855068s
client  | [HQ-req] send_bytes:17, recv_bytes:10240, path_info:0-1-9-17-10240
client  | task[0], fin_cnt: 1, fin_flag: 0
client  | [HQ-req] send_bytes:17, recv_bytes:5120, path_info:0-1-5-17-5120
client  | task[0], fin_cnt: 2, fin_flag: 1
server  | 1.522 DEBUG [Server c72197c43fb6b7c5] pn=16 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 35
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  | 1.522 INFO [Server c72197c43fb6b7c5] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.522 DEBUG [Server c72197c43fb6b7c5] State change from Confirmed -> Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 803, tv_nsec: 237724216 } }
server  | 1.522 DEBUG [pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370] Path validated Instant { tv_sec: 803, tv_nsec: 21316885 }
server  | 1.522 DEBUG [Server c72197c43fb6b7c5] output_path send_profile SendProfile { limit: 1452, pto: None, probe: EnumSet(), paced: false }
server  | 1.522 DEBUG Building Short dcid Some(CID [8]: ac8648e042cd34b2)
server  | 1.522 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 803, tv_nsec: 21316885 }
server  | 1.522 DEBUG [Server c72197c43fb6b7c5] pn=23 type=Short pri-path:ac8648e042cd34b2 [::]:443->[fd00:cafe:cafe::100]:52370 Tos(Cs0, NotEct) len 35
server  |   TX -> Ack { largest_acknowledged: 16, ack_delay: 0, first_ack_range: 11, ack_ranges: [], ecn_count: None }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 1.522 DEBUG Setting timeout of 216.243474ms
server  | 1.522 DEBUG Setting timeout of 216.227884ms
server  | 1.553 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 803, tv_nsec: 237724216 } }; Total: 3
server  | 1.553 DEBUG Setting timeout of 185.431967ms
server  | 1.553 DEBUG Setting timeout of 185.391171ms
server  | 1.739 DEBUG [Server c72197c43fb6b7c5] State change from Draining { error: Transport(Peer(0)), timeout: Instant { tv_sec: 803, tv_nsec: 237724216 } } -> Closed(Transport(Peer(0)))
server  | 1.739 INFO Closing timer expired
client  | task finished, total task_req_cnt: 2, req_fin_cnt: 2, req_sent_cnt: 0, req_create_cnt: 2
client  | all tasks are finished, will break loop and exit
client  | 

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

2025-09-12 05:10:32,003 Using the client's key log file.
2025-09-12 05:10:32,015 
2025-09-12 05:10:32,016 Using the client's key log file.
2025-09-12 05:10:32,016 Using the client's key log file.
2025-09-12 05:10:32,027 
2025-09-12 05:10:32,027 Using the client's key log file.
2025-09-12 05:10:32,484 Check of downloaded files succeeded.
2025-09-12 05:10:32,945 Check of downloaded files succeeded.