[2025-04-30T10:36:02.074739387Z INFO quiche_server] listening on [::]:443 [2025-04-30T10:36:02.074759735Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:36:02.074765947Z TRACE quiche_server] GSO detected: false [2025-04-30T10:36:02.881692797Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57149 to [::]:443 [2025-04-30T10:36:02.881727402Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:36:02.881737781Z WARN quiche_server] Doing version negotiation [2025-04-30T10:36:02.881832980Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57149 to [::]:443 [2025-04-30T10:36:02.881842728Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:36:02.881848389Z WARN quiche_server] Doing version negotiation [2025-04-30T10:36:02.881879037Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:57149 to [::]:443 [2025-04-30T10:36:02.881885629Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T10:36:02.881890478Z WARN quiche_server] Doing version negotiation [2025-04-30T10:36:02.881942166Z TRACE quiche_server] recv() would block [2025-04-30T10:36:03.822525019Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:03.822558702Z TRACE quiche_server] got packet Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= [2025-04-30T10:36:03.822567790Z DEBUG quiche_server] New connection: dcid=bf38a5178dceab2e4ffd3c79ed scid=98e7199634474a727fbc880628214c3f8471b154 [2025-04-30T10:36:03.822799646Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= len=1169 pn=0 [2025-04-30T10:36:03.822812680Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CRYPTO off=0 len=248 [2025-04-30T10:36:03.822839931Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T10:36:03.822844240Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T10:36:03.822945169Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 write message lvl=Initial len=90 [2025-04-30T10:36:03.822977801Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 set write secret lvl=Handshake [2025-04-30T10:36:03.823051840Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 write message lvl=Handshake len=702 [2025-04-30T10:36:03.823055407Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 set write secret lvl=OneRTT [2025-04-30T10:36:03.823063031Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 set read secret lvl=Handshake [2025-04-30T10:36:03.823084271Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm PADDING len=900 [2025-04-30T10:36:03.823105982Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 1200 bytes [2025-04-30T10:36:03.823127723Z TRACE quiche_server] recv() would block [2025-04-30T10:36:03.823140497Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Initial version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=99 pn=0 [2025-04-30T10:36:03.823144444Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=44 blocks=[0..0] ecn_counts=None [2025-04-30T10:36:03.823149705Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm CRYPTO off=0 len=90 [2025-04-30T10:36:03.823159784Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=998.970134ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 255, tv_nsec: 174685593 }, next_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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-30T10:36:03.823191223Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Handshake version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=706 pn=1 [2025-04-30T10:36:03.823194769Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm CRYPTO off=0 len=702 [2025-04-30T10:36:03.823201502Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=998.928726ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=914 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 255, tv_nsec: 174685593 }, next_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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-30T10:36:03.823260473Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 255, tv_nsec: 174685593 } }) [2025-04-30T10:36:03.823267656Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:03.823272997Z TRACE quiche_server] recv() would block [2025-04-30T10:36:03.823277154Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:03.823280070Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:03.967872578Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:03.967890081Z TRACE quiche_server] got packet Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= [2025-04-30T10:36:03.967900911Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= len=1169 pn=1 [2025-04-30T10:36:03.967909938Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CRYPTO off=0 len=248 [2025-04-30T10:36:03.967930246Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm PADDING len=900 [2025-04-30T10:36:03.967944313Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 1200 bytes [2025-04-30T10:36:03.967949873Z TRACE quiche_server] recv() would block [2025-04-30T10:36:03.967960203Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Initial version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=5 pn=2 [2025-04-30T10:36:03.967963980Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=7 blocks=[0..1] ecn_counts=None [2025-04-30T10:36:03.967974229Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=854.155739ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=914 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 255, tv_nsec: 319507763 }, next_time: Instant { tv_sec: 255, tv_nsec: 319507763 }, 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-30T10:36:03.968040864Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 255, tv_nsec: 319507763 } }) [2025-04-30T10:36:03.968048649Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:03.968053939Z TRACE quiche_server] recv() would block [2025-04-30T10:36:03.968058127Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:03.968061142Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.268552993Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:04.268584042Z TRACE quiche_server] got packet Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= [2025-04-30T10:36:04.268598750Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= len=1169 pn=2 [2025-04-30T10:36:04.268611784Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CRYPTO off=0 len=248 [2025-04-30T10:36:04.268627173Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm PADDING len=900 [2025-04-30T10:36:04.268647882Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 1200 bytes [2025-04-30T10:36:04.268654565Z TRACE quiche_server] recv() would block [2025-04-30T10:36:04.268682056Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Initial version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=5 pn=3 [2025-04-30T10:36:04.268686294Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=10 blocks=[0..2] ecn_counts=None [2025-04-30T10:36:04.268699750Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=553.429717ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=914 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 255, tv_nsec: 620213957 }, next_time: Instant { tv_sec: 255, tv_nsec: 620213957 }, 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-30T10:36:04.268788046Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 255, tv_nsec: 620213957 } }) [2025-04-30T10:36:04.268817010Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.268826458Z TRACE quiche_server] recv() would block [2025-04-30T10:36:04.268834533Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:04.268839242Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.823474110Z TRACE quiche_server] timed out [2025-04-30T10:36:04.823506531Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 loss detection timeout expired [2025-04-30T10:36:04.823514767Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=997.61465ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=914 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 255, tv_nsec: 620213957 }, next_time: Instant { tv_sec: 255, tv_nsec: 620213957 }, 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-30T10:36:04.823568287Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Initial version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=102 pn=4 [2025-04-30T10:36:04.823573026Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=69371 blocks=[0..2] ecn_counts=None [2025-04-30T10:36:04.823579298Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm CRYPTO off=0 len=90 [2025-04-30T10:36:04.823598254Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=997.531924ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1071 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 256, tv_nsec: 175093005 }, next_time: Instant { tv_sec: 256, tv_nsec: 175093005 }, 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-30T10:36:04.823700987Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 256, tv_nsec: 175093005 } }) [2025-04-30T10:36:04.823714122Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.823723940Z TRACE quiche_server] recv() would block [2025-04-30T10:36:04.823731545Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:04.823736574Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.869389528Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:04.869402673Z TRACE quiche_server] got packet Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= [2025-04-30T10:36:04.869411810Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Initial version=1 dcid=bf38a5178dceab2e4ffd3c79ed scid=759a1e2f2939a222 token= len=1169 pn=3 [2025-04-30T10:36:04.869428461Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CRYPTO off=0 len=248 [2025-04-30T10:36:04.869437718Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm PADDING len=900 [2025-04-30T10:36:04.869475029Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 1200 bytes [2025-04-30T10:36:04.869483184Z TRACE quiche_server] recv() would block [2025-04-30T10:36:04.869491570Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Initial version=1 dcid=759a1e2f2939a222 scid=98e7199634474a727fbc880628214c3f8471b154 len=5 pn=5 [2025-04-30T10:36:04.869494496Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=10 blocks=[0..3] ecn_counts=None [2025-04-30T10:36:04.869503372Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=951.626866ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1071 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, first_sent_time: Instant { tv_sec: 255, tv_nsec: 174685593 }, 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: 256, tv_nsec: 221040493 }, next_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, 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-30T10:36:04.869545031Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 256, tv_nsec: 221040493 } }) [2025-04-30T10:36:04.869550551Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:04.869554378Z TRACE quiche_server] recv() would block [2025-04-30T10:36:04.869557634Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:04.869559969Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:05.327919430Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:05.327943625Z TRACE quiche_server] got packet Initial version=1 dcid=98e7199634474a727fbc880628214c3f8471b154 scid=759a1e2f2939a222 token= [2025-04-30T10:36:05.327957983Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Initial version=1 dcid=98e7199634474a727fbc880628214c3f8471b154 scid=759a1e2f2939a222 token= len=977 pn=4 [2025-04-30T10:36:05.327982509Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm ACK delay=213 blocks=[0..0] ecn_counts=None [2025-04-30T10:36:05.327991065Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 packet newly acked 0 [2025-04-30T10:36:05.328001614Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm PADDING len=953 [2025-04-30T10:36:05.328027814Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Handshake version=1 dcid=98e7199634474a727fbc880628214c3f8471b154 scid=759a1e2f2939a222 len=62 pn=5 [2025-04-30T10:36:05.328033545Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm ACK delay=91 blocks=[1..1] ecn_counts=None [2025-04-30T10:36:05.328045537Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 packet newly acked 1 [2025-04-30T10:36:05.328050036Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CRYPTO off=0 len=36 [2025-04-30T10:36:05.328070394Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 set read secret lvl=OneRTT [2025-04-30T10:36:05.328110780Z TRACE quiche::tls] 98e7199634474a727fbc880628214c3f8471b154 write message lvl=OneRTT len=396 [2025-04-30T10:36:05.328122382Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 dropped epoch 1 state [2025-04-30T10:36:05.328127021Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 15728640, initial_max_stream_data_bidi_local: 6291456, initial_max_stream_data_bidi_remote: 0, initial_max_stream_data_uni: 32768, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(759a1e2f2939a222), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:36:05.328150475Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 dropped epoch 0 state [2025-04-30T10:36:05.328154352Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false len=65 pn=6 [2025-04-30T10:36:05.328161195Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[0c, ba, 40, 80, 5e, 16, 70, 67] reset_token=[80, a7, df, f8, 40, 45, f2, e5, 30, f1, 8b, 53, c2, e8, 1a, c2] [2025-04-30T10:36:05.328168529Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:36:05.328178207Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 1200 bytes [2025-04-30T10:36:05.328182876Z DEBUG quiche_apps::common] 98e7199634474a727fbc880628214c3f8471b154 response stream 0 is writable with capacity Ok(13500) [2025-04-30T10:36:05.328190360Z TRACE quiche_apps::common] 98e7199634474a727fbc880628214c3f8471b154 received 17 bytes [2025-04-30T10:36:05.328193435Z TRACE quiche_apps::common] 98e7199634474a727fbc880628214c3f8471b154 stream 0 has 17 bytes (fin? true) [2025-04-30T10:36:05.328198655Z INFO quiche_apps::common] 98e7199634474a727fbc880628214c3f8471b154 got GET request for "/www/hkngxdtyey" on stream 0 [2025-04-30T10:36:05.328236607Z INFO quiche_apps::common] 98e7199634474a727fbc880628214c3f8471b154 sending response of size 1024 on stream 0 [2025-04-30T10:36:05.328246816Z TRACE quiche_server] recv() would block [2025-04-30T10:36:05.328255432Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T10:36:05.328265481Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Short dcid=759a1e2f2939a222 key_phase=false len=1324 pn=6 [2025-04-30T10:36:05.328268497Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=12 blocks=[6..6] ecn_counts=None [2025-04-30T10:36:05.328271763Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b7, 9c, a4, be, f6, 11, c8, de, 45, f9, 2d, 2a, 36, d4, a6, 83, de, c5, 44, 7c] reset_token=[dc, 30, c3, c4, 59, 93, 5e, 64, b8, 76, bc, 1e, 51, 15, 00, e8] [2025-04-30T10:36:05.328277283Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[a4, fa, d5, 18, 8e, 83, 20, e3, 22, 62, 01, 7a, 75, aa, 9f, 24, 15, a6, cf, 73] reset_token=[6a, 62, 4b, 02, 3e, e7, 6f, a2, ff, 36, 50, db, 21, 41, 75, f3] [2025-04-30T10:36:05.328286951Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ea, 70, e5, 9e, 20, 6d, c3, a1, b7, 22, 38, b2, ee, 0d, 13, a9, 0e, 8d, fb, 88] reset_token=[38, bc, f9, 09, ea, ef, 3a, 9b, bd, 19, e1, 22, 92, c1, d0, da] [2025-04-30T10:36:05.328292191Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[91, 67, 68, 5b, d7, 3e, 02, 81, 0a, 2f, fe, 36, 08, ad, 29, f3, d2, 56, 5c, 79] reset_token=[f3, 1c, 9a, 9b, 8f, e9, 40, f1, 1a, 4e, 7e, d1, b6, ad, d4, 75] [2025-04-30T10:36:05.328297491Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[07, a9, dc, 37, 12, b1, 17, 51, e8, 3f, 69, 1b, 1b, 2e, 07, d2, 93, 91, c7, da] reset_token=[3a, 03, 2c, be, 4a, f4, 78, ce, 98, a2, d9, e0, 62, 17, e0, 16] [2025-04-30T10:36:05.328302691Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[07, 7c, a2, 8c, a7, 16, 0d, 5c, 8f, ce, 17, 39, b5, 48, 06, 1e, 09, f2, f7, f7] reset_token=[a3, 5a, 50, c5, 97, 73, 2c, e3, 87, cd, 53, 22, 56, c6, d8, e2] [2025-04-30T10:36:05.328307841Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[15, 45, 29, ed, fe, c4, 90, 0e, 7a, 54, 56, 81, 97, 21, 6a, 99, d5, f8, 9e, df] reset_token=[27, 9a, 27, a2, fe, 86, 1c, c1, 64, 75, f6, 5b, 84, 4b, c8, fa] [2025-04-30T10:36:05.328312820Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm HANDSHAKE_DONE [2025-04-30T10:36:05.328315084Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm CRYPTO off=0 len=396 [2025-04-30T10:36:05.328317409Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm STREAM id=0 off=0 len=633 fin=false [2025-04-30T10:36:05.328351303Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=3.787039037s latest_rtt=1.504896454s srtt=1.504832869s min_rtt=1.504823787s rttvar=564.327085ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 914, delivered_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { delivery_rate: 607, is_app_limited: true, interval: 1.504823787s, delivered: 914, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 255, tv_nsec: 174685593 }), send_elapsed: 0ns, ack_elapsed: 1.504823787s, rtt: 1.504823787s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11213, last_update: Instant { tv_sec: 256, tv_nsec: 221040493 }, next_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, 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-30T10:36:05.328369257Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=12150 out_len=1350 left=1324 [2025-04-30T10:36:05.328372873Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Short dcid=759a1e2f2939a222 key_phase=false len=397 pn=7 [2025-04-30T10:36:05.328375418Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm STREAM id=0 off=633 len=391 fin=true [2025-04-30T10:36:05.328380478Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=3.787127854s latest_rtt=1.504896454s srtt=1.504832869s min_rtt=1.504823787s rttvar=564.327085ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1773 app_limited=true congestion_recovery_start_time=None Rate { delivered: 914, delivered_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 1, rate_sample: RateSample { delivery_rate: 607, is_app_limited: true, interval: 1.504823787s, delivered: 914, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 255, tv_nsec: 174685593 }), send_elapsed: 0ns, ack_elapsed: 1.504823787s, rtt: 1.504823787s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11213, last_update: Instant { tv_sec: 256, tv_nsec: 221040493 }, next_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, 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-30T10:36:05.328440571Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 1773 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 256, tv_nsec: 221040493 } }) [2025-04-30T10:36:05.328461951Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:05.328467151Z TRACE quiche_server] recv() would block [2025-04-30T10:36:05.328469966Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:05.328472270Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:06.072228310Z TRACE quiche_server] got 66 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:06.072261142Z TRACE quiche_server] got packet Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false [2025-04-30T10:36:06.072275489Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false len=45 pn=7 [2025-04-30T10:36:06.072298152Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[c4, b3, 95, 53, 64, cb, a4, 61] reset_token=[77, 8d, 9a, 02, 51, d1, b6, 33, cb, 98, 2b, 48, d5, cb, 67, e2] [2025-04-30T10:36:06.072320915Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 66 bytes [2025-04-30T10:36:06.072328018Z TRACE quiche_server] recv() would block [2025-04-30T10:36:06.072337295Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 pmtud probe status false hs_con=true hs_sent=true cwnd_avail=11727 out_len=1350 left=1319 [2025-04-30T10:36:06.072343417Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx pkt Short dcid=759a1e2f2939a222 key_phase=false len=5 pn=8 [2025-04-30T10:36:06.072346673Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 tx frm ACK delay=7 blocks=[6..7] ecn_counts=None [2025-04-30T10:36:06.072358756Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 timer=3.043148974s latest_rtt=1.504896454s srtt=1.504832869s min_rtt=1.504823787s rttvar=564.327085ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1773 app_limited=true congestion_recovery_start_time=None Rate { delivered: 914, delivered_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, end_of_app_limited: 6, last_sent_packet: 8, largest_acked: 1, rate_sample: RateSample { delivery_rate: 607, is_app_limited: true, interval: 1.504823787s, delivered: 914, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 255, tv_nsec: 174685593 }), send_elapsed: 0ns, ack_elapsed: 1.504823787s, rtt: 1.504823787s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11213, last_update: Instant { tv_sec: 256, tv_nsec: 221040493 }, next_time: Instant { tv_sec: 256, tv_nsec: 221040493 }, 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-30T10:36:06.072440490Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 written 31 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:39314, at: Instant { tv_sec: 256, tv_nsec: 221040493 } }) [2025-04-30T10:36:06.072470677Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:06.072476988Z TRACE quiche_server] recv() would block [2025-04-30T10:36:06.072480325Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:06.072483170Z TRACE quiche_server] Collecting garbage [2025-04-30T10:36:06.830821501Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:06.830861296Z TRACE quiche_server] got packet Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false [2025-04-30T10:36:06.830877036Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false len=23 pn=8 [2025-04-30T10:36:06.830900680Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm ACK delay=6 blocks=[6..7] ecn_counts=None [2025-04-30T10:36:06.830909837Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 packet newly acked 6 [2025-04-30T10:36:06.830917682Z TRACE quiche::recovery::congestion::recovery] 98e7199634474a727fbc880628214c3f8471b154 packet newly acked 7 [2025-04-30T10:36:06.830948520Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 44 bytes [2025-04-30T10:36:06.830958840Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:39314 to [::]:443 [2025-04-30T10:36:06.830964210Z TRACE quiche_server] got packet Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false [2025-04-30T10:36:06.830970391Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx pkt Short dcid=98e7199634474a727fbc880628214c3f8471b154 key_phase=false len=21 pn=9 [2025-04-30T10:36:06.830977224Z TRACE quiche] 98e7199634474a727fbc880628214c3f8471b154 rx frm CONNECTION_CLOSE err=0 frame=0 reason=[] [2025-04-30T10:36:06.830985931Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 processed 42 bytes [2025-04-30T10:36:06.830992062Z TRACE quiche_server] recv() would block [2025-04-30T10:36:06.830996971Z TRACE quiche_server] 98e7199634474a727fbc880628214c3f8471b154 done writing [2025-04-30T10:36:06.831001690Z TRACE quiche_server] Collecting garbage