[2025-04-30T09:46:32.444298815Z INFO quiche_server] listening on [::]:443 [2025-04-30T09:46:32.444322710Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T09:46:32.444329412Z TRACE quiche_server] GSO detected: false [2025-04-30T09:46:33.268286567Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:56269 to [::]:443 [2025-04-30T09:46:33.268325680Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:46:33.268335428Z WARN quiche_server] Doing version negotiation [2025-04-30T09:46:33.268453188Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:56269 to [::]:443 [2025-04-30T09:46:33.268462415Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:46:33.268468115Z WARN quiche_server] Doing version negotiation [2025-04-30T09:46:33.268498622Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:56269 to [::]:443 [2025-04-30T09:46:33.268504894Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T09:46:33.268509793Z WARN quiche_server] Doing version negotiation [2025-04-30T09:46:33.268533447Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.215472034Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:34.215496530Z TRACE quiche_server] got packet Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= [2025-04-30T09:46:34.215505667Z DEBUG quiche_server] New connection: dcid=c0666ec464837356 scid=206c2316e4678f7a2fae6de1fb308da921e6570c [2025-04-30T09:46:34.215719014Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= len=1226 pn=100007 [2025-04-30T09:46:34.215732640Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PING mtu_probe=None [2025-04-30T09:46:34.215737078Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm CRYPTO off=0 len=285 [2025-04-30T09:46:34.215764499Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T09:46:34.215768787Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T09:46:34.215880896Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c write message lvl=Initial len=123 [2025-04-30T09:46:34.215908798Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c set write secret lvl=Handshake [2025-04-30T09:46:34.215963710Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c write message lvl=Handshake len=697 [2025-04-30T09:46:34.215966726Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c set write secret lvl=OneRTT [2025-04-30T09:46:34.215972807Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c set read secret lvl=Handshake [2025-04-30T09:46:34.215990641Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=916 [2025-04-30T09:46:34.216009807Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 1252 bytes [2025-04-30T09:46:34.216027219Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.216038229Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Initial version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=135 pn=0 [2025-04-30T09:46:34.216041466Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=42 blocks=[100007..100007] ecn_counts=None [2025-04-30T09:46:34.216045743Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm CRYPTO off=0 len=123 [2025-04-30T09:46:34.216053899Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=998.974843ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=190 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 224, tv_nsec: 2968012 }, next_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:34.216121214Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Handshake version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=701 pn=1 [2025-04-30T09:46:34.216124681Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm CRYPTO off=0 len=697 [2025-04-30T09:46:34.216130962Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=998.89811ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=945 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 224, tv_nsec: 2968012 }, next_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:34.216173993Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 224, tv_nsec: 2968012 } }) [2025-04-30T09:46:34.216182839Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:34.216187668Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.216191605Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:34.216193940Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:34.460667702Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:34.460697387Z TRACE quiche_server] got packet Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= [2025-04-30T09:46:34.460711683Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= len=1226 pn=100008 [2025-04-30T09:46:34.460723295Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PING mtu_probe=None [2025-04-30T09:46:34.460727854Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm CRYPTO off=0 len=285 [2025-04-30T09:46:34.460748031Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=916 [2025-04-30T09:46:34.460767057Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 1252 bytes [2025-04-30T09:46:34.460773018Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.460784910Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Initial version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=8 pn=2 [2025-04-30T09:46:34.460788697Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=9 blocks=[100007..100008] ecn_counts=None [2025-04-30T09:46:34.460810678Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=754.217943ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=945 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 224, tv_nsec: 247714373 }, next_time: Instant { tv_sec: 224, tv_nsec: 247714373 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:34.460873295Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 224, tv_nsec: 247714373 } }) [2025-04-30T09:46:34.460880228Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:34.460885768Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.460889816Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:34.460892751Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:34.961285197Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:34.961317047Z TRACE quiche_server] got packet Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= [2025-04-30T09:46:34.961331394Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= len=1226 pn=100009 [2025-04-30T09:46:34.961345991Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PING mtu_probe=None [2025-04-30T09:46:34.961352473Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm CRYPTO off=0 len=285 [2025-04-30T09:46:34.961369474Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=916 [2025-04-30T09:46:34.961388520Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 1252 bytes [2025-04-30T09:46:34.961395222Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.961408257Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Initial version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=8 pn=3 [2025-04-30T09:46:34.961411994Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=9 blocks=[100007..100009] ecn_counts=None [2025-04-30T09:46:34.961424277Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=253.604404ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=945 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 224, tv_nsec: 748336627 }, next_time: Instant { tv_sec: 224, tv_nsec: 748336627 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:34.961508474Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 224, tv_nsec: 748336627 } }) [2025-04-30T09:46:34.961515867Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:34.961521458Z TRACE quiche_server] recv() would block [2025-04-30T09:46:34.961525485Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:34.961528391Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.215835201Z TRACE quiche_server] timed out [2025-04-30T09:46:35.215856400Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c loss detection timeout expired [2025-04-30T09:46:35.215864305Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=998.164096ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=945 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 224, tv_nsec: 748336627 }, next_time: Instant { tv_sec: 224, tv_nsec: 748336627 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:35.215910060Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Initial version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=138 pn=4 [2025-04-30T09:46:35.215914419Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=31822 blocks=[100007..100009] ecn_counts=None [2025-04-30T09:46:35.215920239Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm CRYPTO off=0 len=123 [2025-04-30T09:46:35.215938183Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=998.090889ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1138 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 225, tv_nsec: 2824144 }, next_time: Instant { tv_sec: 225, tv_nsec: 2824144 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:35.216007632Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 225, tv_nsec: 2824144 } }) [2025-04-30T09:46:35.216016138Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.216033911Z TRACE quiche_server] recv() would block [2025-04-30T09:46:35.216038209Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:35.216041135Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.461844856Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:35.461875312Z TRACE quiche_server] got packet Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= [2025-04-30T09:46:35.461889148Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Initial version=1 dcid=c0666ec464837356 scid=e312d135df570c8a token= len=1226 pn=100010 [2025-04-30T09:46:35.461900970Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PING mtu_probe=None [2025-04-30T09:46:35.461905539Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm CRYPTO off=0 len=285 [2025-04-30T09:46:35.461919585Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=916 [2025-04-30T09:46:35.461939342Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 1252 bytes [2025-04-30T09:46:35.461945573Z TRACE quiche_server] recv() would block [2025-04-30T09:46:35.461958117Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Initial version=1 dcid=e312d135df570c8a scid=206c2316e4678f7a2fae6de1fb308da921e6570c len=8 pn=5 [2025-04-30T09:46:35.461962144Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=8 blocks=[100007..100010] ecn_counts=None [2025-04-30T09:46:35.461975199Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=752.053553ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1138 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, first_sent_time: Instant { tv_sec: 224, tv_nsec: 2968012 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 225, tv_nsec: 248886918 }, next_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:35.462045279Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 225, tv_nsec: 248886918 } }) [2025-04-30T09:46:35.462052392Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.462057893Z TRACE quiche_server] recv() would block [2025-04-30T09:46:35.462061860Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:35.462087608Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.718464176Z TRACE quiche_server] got 412 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:35.718495815Z TRACE quiche_server] got packet Handshake version=1 dcid=206c2316e4678f7a2fae6de1fb308da921e6570c scid=e312d135df570c8a [2025-04-30T09:46:35.718510823Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Handshake version=1 dcid=206c2316e4678f7a2fae6de1fb308da921e6570c scid=e312d135df570c8a len=64 pn=0 [2025-04-30T09:46:35.718524057Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm ACK delay=45 blocks=[1..1] ecn_counts=None [2025-04-30T09:46:35.718532043Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c packet newly acked 1 [2025-04-30T09:46:35.718554073Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm CRYPTO off=0 len=36 [2025-04-30T09:46:35.718577798Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c set read secret lvl=OneRTT [2025-04-30T09:46:35.718624775Z TRACE quiche::tls] 206c2316e4678f7a2fae6de1fb308da921e6570c write message lvl=OneRTT len=396 [2025-04-30T09:46:35.718635986Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c dropped epoch 1 state [2025-04-30T09:46:35.718640685Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("P-256") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 180000, stateless_reset_token: None, max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(e312d135df570c8a), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T09:46:35.718677434Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c dropped epoch 0 state [2025-04-30T09:46:35.718681601Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Short dcid=206c2316e4678f7a2fae6de1fb308da921e6570c key_phase=false len=290 pn=0 [2025-04-30T09:46:35.718689035Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[c4, cc, e2, 9d, f9, d6, 6c, 94] reset_token=[cb, 11, 51, 58, f5, e4, cf, 5b, 49, 9f, a3, 78, 6c, 60, 44, 80] [2025-04-30T09:46:35.718697591Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[30, f8, 11, 46, c3, 1b, ad, 47] reset_token=[d1, bd, 52, f0, be, 7e, f2, 86, 26, 17, 5f, a7, 62, ee, e1, 8d] [2025-04-30T09:46:35.718703592Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[d9, 97, cf, bf, 99, 08, ab, b2] reset_token=[7f, 46, 5a, 68, 1a, af, 91, d4, 2d, 10, cd, 8e, 29, 80, 3f, 4b] [2025-04-30T09:46:35.718709042Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[e1, 79, c7, 1c, 5f, b2, 53, 2f] reset_token=[12, 36, 50, da, 21, 63, 6b, 49, e6, 3d, 13, 9d, 41, 23, 53, 09] [2025-04-30T09:46:35.718715214Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[59, 6d, 51, 84, 96, c8, 84, fb] reset_token=[7d, 9c, ab, 4a, 21, ad, d6, 08, ef, 0f, 47, 4b, d5, 99, 4c, cb] [2025-04-30T09:46:35.718721215Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[65, 50, d2, 40, 25, 93, b5, c7] reset_token=[a2, d5, 6a, d0, f4, 5b, 3e, 29, 00, 05, bf, f0, 6b, e5, a2, 1c] [2025-04-30T09:46:35.718727116Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[50, 01, ed, 0c, 74, 4d, b0, 86] reset_token=[03, 46, 86, e1, 73, 6f, 58, 12, 43, 7f, 9b, 5f, 3b, 28, ee, 61] [2025-04-30T09:46:35.718732095Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=77 [2025-04-30T09:46:35.718742525Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 412 bytes [2025-04-30T09:46:35.718760879Z TRACE quiche_server] got 183 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:35.718764877Z TRACE quiche_server] got packet Short dcid=206c2316e4678f7a2fae6de1fb308da921e6570c key_phase=false [2025-04-30T09:46:35.718769826Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Short dcid=206c2316e4678f7a2fae6de1fb308da921e6570c key_phase=false len=162 pn=1 [2025-04-30T09:46:35.718775065Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T09:46:35.718786026Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm PADDING len=125 [2025-04-30T09:46:35.718791676Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 183 bytes [2025-04-30T09:46:35.718794953Z DEBUG quiche_apps::common] 206c2316e4678f7a2fae6de1fb308da921e6570c response stream 0 is writable with capacity Ok(13500) [2025-04-30T09:46:35.718802106Z TRACE quiche_apps::common] 206c2316e4678f7a2fae6de1fb308da921e6570c received 17 bytes [2025-04-30T09:46:35.718805212Z TRACE quiche_apps::common] 206c2316e4678f7a2fae6de1fb308da921e6570c stream 0 has 17 bytes (fin? true) [2025-04-30T09:46:35.718810441Z INFO quiche_apps::common] 206c2316e4678f7a2fae6de1fb308da921e6570c got GET request for "/www/aegbbvneuf" on stream 0 [2025-04-30T09:46:35.718847420Z INFO quiche_apps::common] 206c2316e4678f7a2fae6de1fb308da921e6570c sending response of size 1024 on stream 0 [2025-04-30T09:46:35.718880131Z TRACE quiche_server] recv() would block [2025-04-30T09:46:35.718889939Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T09:46:35.718901200Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Short dcid=e312d135df570c8a key_phase=false len=1324 pn=6 [2025-04-30T09:46:35.718904767Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm ACK delay=14 blocks=[0..1] ecn_counts=None [2025-04-30T09:46:35.718908755Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[84, 4a, 65, 89, ac, 31, 46, de, 9b, 4a, 87, b6, 5f, de, 3a, fe, 4f, 8b, 81, 14] reset_token=[81, 3c, 7c, 56, b7, ce, ef, b2, bd, 7f, 23, 63, 2c, e1, d9, a5] [2025-04-30T09:46:35.718915958Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[bb, 6d, 27, 80, a2, e3, 9e, 76, 05, 12, 94, d1, 3a, a0, 60, 9d, 4c, 98, 3d, 23] reset_token=[92, 90, e3, 34, f8, 64, 5b, ee, eb, b3, 93, d0, 6e, 4f, 66, a8] [2025-04-30T09:46:35.718922460Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[e1, a2, 32, f1, d9, 4f, 84, c7, 44, 77, 86, e8, b2, fb, 48, 8b, e2, 69, c8, b2] reset_token=[0a, 83, e8, 50, 75, 85, 27, ec, 7f, 40, 0d, 8b, 86, c1, 93, ed] [2025-04-30T09:46:35.718929002Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[6b, 6c, 63, a6, fb, 87, 87, 20, 23, c4, 1c, 74, 6e, f8, 7e, ed, d4, 54, 8f, 36] reset_token=[dc, 12, 25, 4b, 7e, 2b, 22, bd, 27, 86, 6d, 5d, 6f, 92, 17, 16] [2025-04-30T09:46:35.718935404Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[56, 22, 27, f1, 1a, 49, 8b, a6, 90, 61, b3, 39, cc, 5e, bd, 8c, fc, e5, 61, ac] reset_token=[3a, 0a, 3a, 6b, 67, 9e, 08, 7f, 5d, d2, fd, f9, 44, 77, a9, 29] [2025-04-30T09:46:35.718941866Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[56, 8c, 71, c3, 53, 20, db, 70, 71, 68, f9, 6d, 61, 74, 05, 8e, 36, 8c, 6e, 79] reset_token=[db, aa, ca, 79, e3, 3d, ab, 37, 71, 9b, 27, 88, 06, 42, ee, c7] [2025-04-30T09:46:35.718948308Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[ca, 3c, 56, fb, 07, 41, 55, 08, 77, 39, 94, b9, 80, 61, 01, 96, 94, 22, be, 45] reset_token=[98, c5, 42, 4f, 84, ee, 64, 5f, 01, b3, cb, 18, bb, b9, a4, 39] [2025-04-30T09:46:35.718954911Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm HANDSHAKE_DONE [2025-04-30T09:46:35.718957876Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm CRYPTO off=0 len=396 [2025-04-30T09:46:35.718960751Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T09:46:35.718977022Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=4.517338242s latest_rtt=1.502477523s srtt=1.502477523s min_rtt=1.502477523s rttvar=751.238761ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, first_sent_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 502, is_app_limited: true, interval: 1.502477523s, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 224, tv_nsec: 2968012 }), send_elapsed: 0ns, ack_elapsed: 1.502477523s, rtt: 1.502477523s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11231, last_update: Instant { tv_sec: 225, tv_nsec: 248886918 }, next_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:35.719002079Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T09:46:35.719006256Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx pkt Short dcid=e312d135df570c8a key_phase=false len=397 pn=7 [2025-04-30T09:46:35.719009392Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c tx frm STREAM id=0 off=633 len=391 fin=true [2025-04-30T09:46:35.719015373Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c timer=4.517416828s latest_rtt=1.502477523s srtt=1.502477523s min_rtt=1.502477523s rttvar=751.238761ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1773 app_limited=true congestion_recovery_start_time=None Rate { delivered: 755, delivered_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, first_sent_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 502, is_app_limited: true, interval: 1.502477523s, delivered: 755, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 224, tv_nsec: 2968012 }), send_elapsed: 0ns, ack_elapsed: 1.502477523s, rtt: 1.502477523s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11231, last_update: Instant { tv_sec: 225, tv_nsec: 248886918 }, next_time: Instant { tv_sec: 225, tv_nsec: 248886918 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T09:46:35.719128795Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c written 1773 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:49059, at: Instant { tv_sec: 225, tv_nsec: 248886918 } }) [2025-04-30T09:46:35.719139885Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:35.719146458Z TRACE quiche_server] recv() would block [2025-04-30T09:46:35.719150175Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:35.719153110Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:37.221297896Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:49059 to [::]:443 [2025-04-30T09:46:37.221329836Z TRACE quiche_server] got packet Short dcid=206c2316e4678f7a2fae6de1fb308da921e6570c key_phase=false [2025-04-30T09:46:37.221343642Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx pkt Short dcid=206c2316e4678f7a2fae6de1fb308da921e6570c key_phase=false len=25 pn=2 [2025-04-30T09:46:37.221356496Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm ACK delay=11 blocks=[6..7] ecn_counts=None [2025-04-30T09:46:37.221389507Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c packet newly acked 6 [2025-04-30T09:46:37.221395208Z TRACE quiche::recovery::congestion::recovery] 206c2316e4678f7a2fae6de1fb308da921e6570c packet newly acked 7 [2025-04-30T09:46:37.221401439Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c rx frm APPLICATION_CLOSE err=0 reason=[] [2025-04-30T09:46:37.221429261Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c processed 46 bytes [2025-04-30T09:46:37.221436745Z TRACE quiche_server] recv() would block [2025-04-30T09:46:37.221439921Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:37.221443047Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:49.362533592Z TRACE quiche_server] timed out [2025-04-30T09:46:49.362578796Z TRACE quiche] 206c2316e4678f7a2fae6de1fb308da921e6570c draining timeout expired [2025-04-30T09:46:49.362628869Z TRACE quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c done writing [2025-04-30T09:46:49.362634450Z TRACE quiche_server] Collecting garbage [2025-04-30T09:46:49.362640301Z INFO quiche_server] 206c2316e4678f7a2fae6de1fb308da921e6570c connection collected recv=8 sent=8 lost=0 retrans=1 sent_bytes=3100 recv_bytes=5649 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:49059 validation_state=Validated active=true recv=8 sent=8 lost=0 retrans=1 rtt=1.53458086s min_rtt=Some(1.502477523s) rttvar=627.635746ms cwnd=13500 sent_bytes=3100 recv_bytes=5649 lost_bytes=0 stream_retrans_bytes=123 pmtu=1350 delivery_rate=1007]