alibaba / xquic

XQUIC Library released by Alibaba is a cross-platform implementation of QUIC and HTTP/3 protocol.
Apache License 2.0
1.7k stars 327 forks source link

[Bug]: xquic client continue retry handshake with quic-go server #57

Closed raulftang closed 2 years ago

raulftang commented 2 years ago

What happened?

A clear and concise description of what the bug is.

Steps To Reproduce

Information and Steps to reproduce the behavior.

Relevant log output

[2022/01/14 10:46:13 695052] [info] |xqc_tls_ctx_create|set cipher suites suc|ciphers:TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256
[2022/01/14 10:46:13 699479] [info] |xqc_tls_ctx_register_alpn|alpn registered|alpn:transport|alpn_list:    transport
[2022/01/14 10:46:13 699500] [info] |xqc_engine_add_alpn|alpn registered|alpn:transport|
[2022/01/14 10:46:13 699665] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:IDLE|expire:1642157183699656|now:1642157173699656|interv:10000000|
[2022/01/14 10:46:13 699679] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:IDLE|expire:1642157183699656|interv:10000000|
[2022/01/14 10:46:13 699703] [rec_parameters_set] |scid:3bdda4c0438ad3a8|xqc_send_ctl_create|reordering_packet_threshold:3|reordering_time_threshold_shift:3|
[2022/01/14 10:46:13 699732] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_create|success|scid:3bdda4c0438ad3a8|dcid:5d63ac8ffa079819|conn:00000000018A2C40|
[2022/01/14 10:46:13 699745] [tra_parameters_set] |scid:3bdda4c0438ad3a8|xqc_conn_create|local|migration:1|max_idle_timeout:120000|max_udp_payload_size:1500|active_connection_id_limit:8|max_data:0|
[2022/01/14 10:46:13 699762] [debug] |scid:3bdda4c0438ad3a8|xqc_create_crypto_stream|encrypt_level:0|cur_state:C_INIT|
[2022/01/14 10:46:13 700009] [debug] |xqc_client_connect|xqc_connect|
[2022/01/14 10:46:13 700029] [connection_started] |scid:3bdda4c0438ad3a8|xqc_client_connect|remote|dst_ip:::1|dst_port:4242|scid:3bdda4c0438ad3a8|dcid:5d63ac8ffa079819|
[2022/01/14 10:46:13 700062] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:13 700075] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INIT|flag:TICKING UPPER_CONN_EXIST CANNOT_DESTROY |now:1642157173700072|
[2022/01/14 10:46:13 700088] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INIT|flag:TICKING UPPER_CONN_EXIST CANNOT_DESTROY |now:1642157173700086|
[2022/01/14 10:46:13 700104] [debug] |scid:3bdda4c0438ad3a8|xqc_process_crypto_write_streams|
[2022/01/14 10:46:13 700126] [info] |scid:3bdda4c0438ad3a8|xqc_crypto_stream_send|crypto send data|pkt_num:0|size:342|sent:312|pkt_type:INIT|frame:CRYPTO |now:1642157173700124|
[2022/01/14 10:46:13 700139] [debug] |scid:3bdda4c0438ad3a8|xqc_crypto_stream_on_write|encrypt_level:0|cur_state:C_INIT|next_state:C_INITIAL_SENT|
[2022/01/14 10:46:13 700219] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:13 700237] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:0|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:0|now:1642157173700171|
[2022/01/14 10:46:13 700248] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:0|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:13 700259] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:0|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:13 700271] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:0|applimit:0|
[2022/01/14 10:46:13 700280] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|Restart from idle|
[2022/01/14 10:46:13 700290] [congestion_state_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|new_state:restart|
[2022/01/14 10:46:13 700302] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 1200|
[2022/01/14 10:46:13 700313] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:13 700322] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:13 700332] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157174450171|now:1642157173700301|interv:749870|
[2022/01/14 10:46:13 700342] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157174450171|interv:749870|
[2022/01/14 10:46:13 700365] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157174450171|now:1642157173700301|interval:749870|pto_count:0|srtt:250000
[2022/01/14 10:46:13 700378] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157174450171|
[2022/01/14 10:46:14 451172] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:14 451260] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157174451251|
[2022/01/14 10:46:14 451297] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157174451294|
[2022/01/14 10:46:14 451327] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157174450171|now:1642157174451294|
[2022/01/14 10:46:14 451360] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157174450171|
[2022/01/14 10:46:14 451392] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:46:14 451422] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000018A2C40|bytes_in_flight:1200|
[2022/01/14 10:46:14 451456] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 1200|
[2022/01/14 10:46:14 451490] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:14 451522] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:14 451554] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:46:14 451593] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:14 451668] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:14 451713] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000018A2C40|pto_count:1
[2022/01/14 10:46:14 451750] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157175951749|now:1642157174451747|interv:1500002|
[2022/01/14 10:46:14 451785] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157175951749|interv:1500002|
[2022/01/14 10:46:14 451818] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157175951749|now:1642157174451747|interval:1500002|pto_count:1|srtt:250000
[2022/01/14 10:46:14 451864] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:14 452056] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:14 452110] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:1|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:0|now:1642157174451957|
[2022/01/14 10:46:14 452145] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:1|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:14 452181] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:1|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:14 452218] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:0|applimit:0|
[2022/01/14 10:46:14 452289] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|Restart from idle|
[2022/01/14 10:46:14 452317] [congestion_state_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|new_state:restart|
[2022/01/14 10:46:14 452338] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 1200|
[2022/01/14 10:46:14 452357] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:14 452376] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:14 452394] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157175951957|now:1642157174452337|interv:1499620|
[2022/01/14 10:46:14 452414] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157175951957|interv:1499620|
[2022/01/14 10:46:14 452433] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157175951957|now:1642157174452337|interval:1499620|pto_count:1|srtt:250000
[2022/01/14 10:46:14 452457] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:14 452556] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:14 452602] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:2|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:1200|now:1642157174452505|
[2022/01/14 10:46:14 452641] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:2|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:14 452677] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:2|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:14 452730] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:1200|applimit:0|
[2022/01/14 10:46:14 452762] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 2400|
[2022/01/14 10:46:14 452793] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:14 452826] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:14 452857] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157175952505|now:1642157174452761|interv:1499744|
[2022/01/14 10:46:14 452890] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157175952505|interv:1499744|
[2022/01/14 10:46:14 452922] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157175952505|now:1642157174452761|interval:1499744|pto_count:1|srtt:250000
[2022/01/14 10:46:14 452963] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157175952505|
[2022/01/14 10:46:15 955746] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:15 955840] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157175955831|
[2022/01/14 10:46:15 955879] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157175955876|
[2022/01/14 10:46:15 955913] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157175952505|now:1642157175955876|
[2022/01/14 10:46:15 955950] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157175952505|
[2022/01/14 10:46:15 956032] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:46:15 956068] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000018A2C40|bytes_in_flight:2400|
[2022/01/14 10:46:15 956102] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 2400|
[2022/01/14 10:46:15 956134] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:15 956166] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:15 956198] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:46:15 956235] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:15 956331] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:15 956371] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000018A2C40|pto_count:2
[2022/01/14 10:46:15 956405] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 1200|
[2022/01/14 10:46:15 956437] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:15 956469] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:15 956504] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157177452505|now:1642157175956403|interv:1496102|
[2022/01/14 10:46:15 956540] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157177452505|interv:1496102|
[2022/01/14 10:46:15 956573] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157177452505|now:1642157175956403|interval:1496102|pto_count:2|srtt:250000
[2022/01/14 10:46:15 956620] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:15 956809] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:15 956863] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:3|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:1200|now:1642157175956713|
[2022/01/14 10:46:15 956898] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:3|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:15 956934] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:3|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:15 956970] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:1200|applimit:0|
[2022/01/14 10:46:15 957005] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 2400|
[2022/01/14 10:46:15 957038] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:15 957058] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:15 957076] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157177957003|now:1642157175957003|interv:2000000|
[2022/01/14 10:46:15 957096] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157177957003|interv:2000000|
[2022/01/14 10:46:15 957134] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157177957003|now:1642157175957003|interval:2000000|pto_count:2|srtt:250000
[2022/01/14 10:46:15 957159] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:15 957256] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:15 957305] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:4|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:2400|now:1642157175957206|
[2022/01/14 10:46:15 957343] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:4|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:15 957379] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:4|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:15 957419] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:2400|applimit:0|
[2022/01/14 10:46:15 957441] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 3600|
[2022/01/14 10:46:15 957460] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:15 957479] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:15 957497] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157177957440|now:1642157175957440|interv:2000000|
[2022/01/14 10:46:15 957516] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157177957440|interv:2000000|
[2022/01/14 10:46:15 957535] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157177957440|now:1642157175957440|interval:2000000|pto_count:2|srtt:250000
[2022/01/14 10:46:15 957559] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157177957440|
[2022/01/14 10:46:17 959281] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:17 959357] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157177959351|
[2022/01/14 10:46:17 959380] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157177959379|
[2022/01/14 10:46:17 959399] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157177957440|now:1642157177959379|
[2022/01/14 10:46:17 959417] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157177957440|
[2022/01/14 10:46:17 959434] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:46:17 959450] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000018A2C40|bytes_in_flight:3600|
[2022/01/14 10:46:17 959468] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 3600|
[2022/01/14 10:46:17 959485] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:17 959502] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:17 959518] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:46:17 959539] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:17 959592] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:17 959625] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000018A2C40|pto_count:3
[2022/01/14 10:46:17 959644] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 3600|
[2022/01/14 10:46:17 959660] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:17 959676] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:17 959693] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157179959643|now:1642157177959643|interv:2000000|
[2022/01/14 10:46:17 959710] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157179959643|interv:2000000|
[2022/01/14 10:46:17 959727] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157179959643|now:1642157177959643|interval:2000000|pto_count:3|srtt:250000
[2022/01/14 10:46:17 959752] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:17 959894] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:17 959935] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:5|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:3600|now:1642157177959807|
[2022/01/14 10:46:17 959967] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:5|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:17 959996] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:5|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:17 960029] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:3600|applimit:0|
[2022/01/14 10:46:17 960057] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 4800|
[2022/01/14 10:46:17 960084] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:17 960109] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:17 960128] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157179960056|now:1642157177960056|interv:2000000|
[2022/01/14 10:46:17 960145] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157179960056|interv:2000000|
[2022/01/14 10:46:17 960162] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157179960056|now:1642157177960056|interval:2000000|pto_count:3|srtt:250000
[2022/01/14 10:46:17 960183] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:17 960269] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:17 960310] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:6|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:4800|now:1642157177960226|
[2022/01/14 10:46:17 960356] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:6|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:17 960413] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:6|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:17 960432] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:4800|applimit:0|
[2022/01/14 10:46:17 960449] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 6000|
[2022/01/14 10:46:17 960465] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:17 960481] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:17 960498] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157179960448|now:1642157177960448|interv:2000000|
[2022/01/14 10:46:17 960515] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157179960448|interv:2000000|
[2022/01/14 10:46:17 960532] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157179960448|now:1642157177960448|interval:2000000|pto_count:3|srtt:250000
[2022/01/14 10:46:17 960553] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157179960448|
[2022/01/14 10:46:19 963729] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:19 963819] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157179963812|
[2022/01/14 10:46:19 963855] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157179963852|
[2022/01/14 10:46:19 963887] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157179960448|now:1642157179963852|
[2022/01/14 10:46:19 963921] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157179960448|
[2022/01/14 10:46:19 963956] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:46:19 963986] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000018A2C40|bytes_in_flight:6000|
[2022/01/14 10:46:19 964020] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 6000|
[2022/01/14 10:46:19 964053] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:19 964086] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:19 964117] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:46:19 964156] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:19 964203] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:19 964279] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000018A2C40|pto_count:4
[2022/01/14 10:46:19 964319] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 6000|
[2022/01/14 10:46:19 964349] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:19 964381] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:19 964412] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157181964317|now:1642157179964317|interv:2000000|
[2022/01/14 10:46:19 964480] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157181964317|interv:2000000|
[2022/01/14 10:46:19 964513] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157181964317|now:1642157179964317|interval:2000000|pto_count:4|srtt:250000
[2022/01/14 10:46:19 964559] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:19 964751] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:19 964792] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:7|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:6000|now:1642157179964658|
[2022/01/14 10:46:19 964829] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:7|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:19 964866] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:7|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:19 964901] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:6000|applimit:0|
[2022/01/14 10:46:19 964935] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 7200|
[2022/01/14 10:46:19 964967] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:19 964999] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:19 965031] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157181964933|now:1642157179964933|interv:2000000|
[2022/01/14 10:46:19 965065] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157181964933|interv:2000000|
[2022/01/14 10:46:19 965097] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157181964933|now:1642157179964933|interval:2000000|pto_count:4|srtt:250000
[2022/01/14 10:46:19 965138] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:19 965263] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:19 965300] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:8|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:7200|now:1642157179965215|
[2022/01/14 10:46:19 965335] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:8|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:19 965371] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:8|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:19 965405] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:7200|applimit:0|
[2022/01/14 10:46:19 965437] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 8400|
[2022/01/14 10:46:19 965468] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:19 965499] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:19 965531] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157181965436|now:1642157179965436|interv:2000000|
[2022/01/14 10:46:19 965591] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157181965436|interv:2000000|
[2022/01/14 10:46:19 965624] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157181965436|now:1642157179965436|interval:2000000|pto_count:4|srtt:250000
[2022/01/14 10:46:19 965663] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157181965436|
[2022/01/14 10:46:21 967272] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:21 967371] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157181967361|
[2022/01/14 10:46:21 967413] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157181967410|
[2022/01/14 10:46:21 967445] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157181965436|now:1642157181967410|
[2022/01/14 10:46:21 967482] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157181965436|
[2022/01/14 10:46:21 967515] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:46:21 967545] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000018A2C40|bytes_in_flight:8400|
[2022/01/14 10:46:21 967576] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 8400|
[2022/01/14 10:46:21 967611] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:21 967642] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:21 967674] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:46:21 967712] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:21 967758] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:46:21 967798] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000018A2C40|pto_count:5
[2022/01/14 10:46:21 967833] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 8400|
[2022/01/14 10:46:21 967864] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:21 967896] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:21 967929] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157183967831|now:1642157181967831|interv:2000000|
[2022/01/14 10:46:21 967963] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157183967831|interv:2000000|
[2022/01/14 10:46:21 967996] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157183967831|now:1642157181967831|interval:2000000|pto_count:5|srtt:250000
[2022/01/14 10:46:21 968057] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:21 968253] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:21 968294] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:9|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:8400|now:1642157181968160|
[2022/01/14 10:46:21 968377] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:9|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:21 968416] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:9|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:21 968454] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:8400|applimit:0|
[2022/01/14 10:46:21 968487] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 9600|
[2022/01/14 10:46:21 968521] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:21 968552] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:21 968584] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157183968486|now:1642157181968486|interv:2000000|
[2022/01/14 10:46:21 968617] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157183968486|interv:2000000|
[2022/01/14 10:46:21 968650] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157183968486|now:1642157181968486|interval:2000000|pto_count:5|srtt:250000
[2022/01/14 10:46:21 968691] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_transmit_pto_probe_packets|conn:00000000018A2C40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:46:21 968815] [datagrams_sent] |scid:3bdda4c0438ad3a8|xqc_send|size:1216|
[2022/01/14 10:46:21 968854] [info] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|<==|conn:00000000018A2C40|pkt_num:10|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:9600|now:1642157181968767|
[2022/01/14 10:46:21 968890] [packet_sent] |scid:3bdda4c0438ad3a8|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:10|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:46:21 968927] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|conn:00000000018A2C40|pkt_num:10|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:46:21 968962] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_on_packet_sent|inflight:9600|applimit:0|
[2022/01/14 10:46:21 968996] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 0, unacked: 10800|
[2022/01/14 10:46:21 969027] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 1, unacked: 0|
[2022/01/14 10:46:21 969058] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_get_pto_time_and_space|conn:00000000018A2C40|PNS: 2, unacked: 0|
[2022/01/14 10:46:21 969090] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157183968994|now:1642157181968994|interv:2000000|
[2022/01/14 10:46:21 969122] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157183968994|interv:2000000|
[2022/01/14 10:46:21 969154] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000018A2C40|expire:1642157183968994|now:1642157181968994|interval:2000000|pto_count:5|srtt:250000
[2022/01/14 10:46:21 969194] [debug] |scid:3bdda4c0438ad3a8|xqc_conn_next_wakeup_time|wakeup_time:1642157183699656|
[2022/01/14 10:46:23 702082] [debug] |xqc_engine_main_logic|
[2022/01/14 10:46:23 702177] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_main_logic|ticking|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157183702168|
[2022/01/14 10:46:23 702213] [debug] |scid:3bdda4c0438ad3a8|xqc_engine_process_conn|conn:00000000018A2C40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST |now:1642157183702210|
[2022/01/14 10:46:23 702289] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|conn:00000000018A2C40|timer expired|type:IDLE|expire_time:1642157183699656|now:1642157183702210|
[2022/01/14 10:46:23 702325] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|expired|type:IDLE|expire_time:1642157183699656|
[2022/01/14 10:46:23 702357] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_expire|unset|type:IDLE|expire_time:1642157183699656|now:1642157183702210|
[2022/01/14 10:46:23 702394] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_unset|type:IDLE|
[2022/01/14 10:46:23 702429] [loss_timer_updated] |scid:3bdda4c0438ad3a8|xqc_send_ctl_timer_unset|cancel|type:IDLE|
[2022/01/14 10:46:23 702465] [report] |scid:3bdda4c0438ad3a8|xqc_conn_destroy|00000000018A2C40|srtt:250000|retrans rate:0.9091|send_count:11|lost_count:0|tlp_count:10|spurious_loss_count:0|recv_count:0|has_0rtt:0|0rtt_accept:0|token_ok:-1|handshake_time:0|first_send_delay:0|conn_persist:10002812|err:0x0|addr or cid not avail|
[2022/01/14 10:46:23 702520] [connection_closed] |scid:3bdda4c0438ad3a8|xqc_conn_destroy|err_code:0|
[2022/01/14 10:46:23 702621] [debug] |scid:3bdda4c0438ad3a8|xqc_send_ctl_destroy|destroy|
[2022/01/14 10:46:23 702834] [debug] |xqc_engine_destroy|begin|
[2022/01/14 10:47:24 253373] [info] |xqc_tls_ctx_create|set cipher suites suc|ciphers:TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256
[2022/01/14 10:47:24 255591] [info] |xqc_tls_ctx_register_alpn|alpn registered|alpn:transport|alpn_list:    transport
[2022/01/14 10:47:24 255614] [info] |xqc_engine_add_alpn|alpn registered|alpn:transport|
[2022/01/14 10:47:24 255759] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:IDLE|expire:1642157254255749|now:1642157244255749|interv:10000000|
[2022/01/14 10:47:24 255772] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:IDLE|expire:1642157254255749|interv:10000000|
[2022/01/14 10:47:24 255788] [rec_parameters_set] |scid:beea546d16caa566|xqc_send_ctl_create|reordering_packet_threshold:3|reordering_time_threshold_shift:3|
[2022/01/14 10:47:24 255817] [debug] |scid:beea546d16caa566|xqc_conn_create|success|scid:beea546d16caa566|dcid:684b83d8fff6361a|conn:00000000009EBC40|
[2022/01/14 10:47:24 255829] [tra_parameters_set] |scid:beea546d16caa566|xqc_conn_create|local|migration:1|max_idle_timeout:120000|max_udp_payload_size:1500|active_connection_id_limit:8|max_data:0|
[2022/01/14 10:47:24 255842] [debug] |scid:beea546d16caa566|xqc_create_crypto_stream|encrypt_level:0|cur_state:C_INIT|
[2022/01/14 10:47:24 256098] [debug] |xqc_client_connect|xqc_connect|
[2022/01/14 10:47:24 256116] [connection_started] |scid:beea546d16caa566|xqc_client_connect|remote|dst_ip:::1|dst_port:4242|scid:beea546d16caa566|dcid:684b83d8fff6361a|
[2022/01/14 10:47:24 256148] [debug] |xqc_engine_main_logic|
[2022/01/14 10:47:24 256166] [debug] |scid:beea546d16caa566|xqc_engine_main_logic|ticking|conn:00000000009EBC40|state:C_INIT|flag:TICKING UPPER_CONN_EXIST CANNOT_DESTROY |now:1642157244256163|
[2022/01/14 10:47:24 256179] [debug] |scid:beea546d16caa566|xqc_engine_process_conn|conn:00000000009EBC40|state:C_INIT|flag:TICKING UPPER_CONN_EXIST CANNOT_DESTROY |now:1642157244256178|
[2022/01/14 10:47:24 256200] [debug] |scid:beea546d16caa566|xqc_process_crypto_write_streams|
[2022/01/14 10:47:24 256220] [info] |scid:beea546d16caa566|xqc_crypto_stream_send|crypto send data|pkt_num:0|size:342|sent:312|pkt_type:INIT|frame:CRYPTO |now:1642157244256218|
[2022/01/14 10:47:24 256237] [debug] |scid:beea546d16caa566|xqc_crypto_stream_on_write|encrypt_level:0|cur_state:C_INIT|next_state:C_INITIAL_SENT|
[2022/01/14 10:47:24 256306] [datagrams_sent] |scid:beea546d16caa566|xqc_send|size:1216|
[2022/01/14 10:47:24 256325] [info] |scid:beea546d16caa566|xqc_send_packet_with_pn|<==|conn:00000000009EBC40|pkt_num:0|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:0|now:1642157244256269|
[2022/01/14 10:47:24 256338] [packet_sent] |scid:beea546d16caa566|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:0|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:47:24 256361] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|conn:00000000009EBC40|pkt_num:0|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:47:24 256372] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|inflight:0|applimit:0|
[2022/01/14 10:47:24 256380] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|Restart from idle|
[2022/01/14 10:47:24 256389] [congestion_state_updated] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|new_state:restart|
[2022/01/14 10:47:24 256399] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 1200|
[2022/01/14 10:47:24 256408] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:24 256417] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:24 256426] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157245006269|now:1642157244256398|interv:749871|
[2022/01/14 10:47:24 256437] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157245006269|interv:749871|
[2022/01/14 10:47:24 256446] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157245006269|now:1642157244256398|interval:749871|pto_count:0|srtt:250000
[2022/01/14 10:47:24 256458] [debug] |scid:beea546d16caa566|xqc_conn_next_wakeup_time|wakeup_time:1642157245006269|
[2022/01/14 10:47:24 256642] [datagrams_received] |scid:beea546d16caa566|xqc_engine_packet_process|size:133|
[2022/01/14 10:47:24 256655] [info] |xqc_engine_packet_process|==>|conn:00000000009EBC40|size:133|state:C_INITIAL_SENT|recv_time:1642157244256639|
[2022/01/14 10:47:24 256663] [connection_started] |scid:beea546d16caa566|xqc_engine_packet_process|local|src_ip:::|src_port:44863|
[2022/01/14 10:47:24 256681] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|packet parse|retry|
[2022/01/14 10:47:24 256698] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|packet_parse_retry|original_dcid not match|
[2022/01/14 10:47:24 256705] [info] |scid:beea546d16caa566|xqc_conn_addr_validated|Address Validated|conn:00000000009EBC40|role:1|
[2022/01/14 10:47:24 256711] [info] |scid:beea546d16caa566|xqc_conn_on_pkt_processed|====>|conn:00000000009EBC40|size:133|pkt_type:RETRY|pkt_num:0|frame:|recv_time:1642157244256639|
[2022/01/14 10:47:24 256718] [packet_received] |scid:beea546d16caa566|xqc_conn_process_packet|pkt_pns:0|pkt_type:3|pkt_num:0|len:133|frame_flag:|
[2022/01/14 10:47:24 256725] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:IDLE|expire:1642157254256639|now:1642157244256639|interv:10000000|
[2022/01/14 10:47:24 256732] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:IDLE|expire:1642157254256639|interv:10000000|
[2022/01/14 10:47:24 256749] [debug] |xqc_engine_main_logic|
[2022/01/14 10:47:24 256766] [debug] |scid:beea546d16caa566|xqc_engine_main_logic|ticking|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:WAIT_WAKEUP TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157244256763|
[2022/01/14 10:47:24 256778] [debug] |scid:beea546d16caa566|xqc_engine_process_conn|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:WAIT_WAKEUP TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157244256776|
[2022/01/14 10:47:24 256791] [debug] |scid:beea546d16caa566|xqc_conn_next_wakeup_time|wakeup_time:1642157245006269|
[2022/01/14 10:47:25 007208] [debug] |xqc_engine_main_logic|
[2022/01/14 10:47:25 007289] [debug] |scid:beea546d16caa566|xqc_engine_main_logic|ticking|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157245007282|
[2022/01/14 10:47:25 007315] [debug] |scid:beea546d16caa566|xqc_engine_process_conn|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157245007313|
[2022/01/14 10:47:25 007364] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157245006269|now:1642157245007313|
[2022/01/14 10:47:25 007386] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157245006269|
[2022/01/14 10:47:25 007405] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:47:25 007424] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000009EBC40|bytes_in_flight:1200|
[2022/01/14 10:47:25 007444] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 1200|
[2022/01/14 10:47:25 007464] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:25 007482] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:25 007501] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:47:25 007524] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:47:25 007567] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:47:25 007590] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000009EBC40|pto_count:1
[2022/01/14 10:47:25 007612] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157246507611|now:1642157245007610|interv:1500001|
[2022/01/14 10:47:25 007632] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157246507611|interv:1500001|
[2022/01/14 10:47:25 007651] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157246507611|now:1642157245007610|interval:1500001|pto_count:1|srtt:250000
[2022/01/14 10:47:25 007678] [debug] |scid:beea546d16caa566|xqc_conn_transmit_pto_probe_packets|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:47:25 007808] [datagrams_sent] |scid:beea546d16caa566|xqc_send|size:1216|
[2022/01/14 10:47:25 007839] [info] |scid:beea546d16caa566|xqc_send_packet_with_pn|<==|conn:00000000009EBC40|pkt_num:1|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:0|now:1642157245007738|
[2022/01/14 10:47:25 007870] [packet_sent] |scid:beea546d16caa566|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:1|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:47:25 007902] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|conn:00000000009EBC40|pkt_num:1|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:47:25 007934] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|inflight:0|applimit:0|
[2022/01/14 10:47:25 007963] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|Restart from idle|
[2022/01/14 10:47:25 007990] [congestion_state_updated] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|new_state:restart|
[2022/01/14 10:47:25 008019] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 1200|
[2022/01/14 10:47:25 008051] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:25 008080] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:25 008110] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157246507738|now:1642157245008018|interv:1499720|
[2022/01/14 10:47:25 008163] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157246507738|interv:1499720|
[2022/01/14 10:47:25 008196] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157246507738|now:1642157245008018|interval:1499720|pto_count:1|srtt:250000
[2022/01/14 10:47:25 008234] [debug] |scid:beea546d16caa566|xqc_conn_transmit_pto_probe_packets|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:47:25 008351] [datagrams_sent] |scid:beea546d16caa566|xqc_send|size:1216|
[2022/01/14 10:47:25 008401] [info] |scid:beea546d16caa566|xqc_send_packet_with_pn|<==|conn:00000000009EBC40|pkt_num:2|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:1200|now:1642157245008303|
[2022/01/14 10:47:25 008429] [packet_sent] |scid:beea546d16caa566|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:2|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:47:25 008458] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|conn:00000000009EBC40|pkt_num:2|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:47:25 008489] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|inflight:1200|applimit:0|
[2022/01/14 10:47:25 008517] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 2400|
[2022/01/14 10:47:25 008536] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:25 008555] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:25 008586] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157246508303|now:1642157245008516|interv:1499787|
[2022/01/14 10:47:25 008605] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157246508303|interv:1499787|
[2022/01/14 10:47:25 008624] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157246508303|now:1642157245008516|interval:1499787|pto_count:1|srtt:250000
[2022/01/14 10:47:25 008650] [debug] |scid:beea546d16caa566|xqc_conn_next_wakeup_time|wakeup_time:1642157246508303|
[2022/01/14 10:47:25 008704] [datagrams_received] |scid:beea546d16caa566|xqc_engine_packet_process|size:133|
[2022/01/14 10:47:25 008749] [info] |xqc_engine_packet_process|==>|conn:00000000009EBC40|size:133|state:C_INITIAL_SENT|recv_time:1642157245008699|
[2022/01/14 10:47:25 008780] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|packet parse|retry|
[2022/01/14 10:47:25 008799] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|retry_count exceed 1 return|
[2022/01/14 10:47:25 008820] [info] |scid:beea546d16caa566|xqc_conn_on_pkt_processed|====>|conn:00000000009EBC40|size:133|pkt_type:RETRY|pkt_num:0|frame:|recv_time:1642157245008699|
[2022/01/14 10:47:25 008841] [packet_received] |scid:beea546d16caa566|xqc_conn_process_packet|pkt_pns:0|pkt_type:3|pkt_num:0|len:133|frame_flag:|
[2022/01/14 10:47:25 008861] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:IDLE|expire:1642157255008699|now:1642157245008699|interv:10000000|
[2022/01/14 10:47:25 008880] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:IDLE|expire:1642157255008699|interv:10000000|
[2022/01/14 10:47:25 008907] [datagrams_received] |scid:beea546d16caa566|xqc_engine_packet_process|size:133|
[2022/01/14 10:47:25 008927] [info] |xqc_engine_packet_process|==>|conn:00000000009EBC40|size:133|state:C_INITIAL_SENT|recv_time:1642157245008905|
[2022/01/14 10:47:25 008972] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|packet parse|retry|
[2022/01/14 10:47:25 009018] [debug] |scid:beea546d16caa566|xqc_packet_parse_retry|retry_count exceed 1 return|
[2022/01/14 10:47:25 009039] [info] |scid:beea546d16caa566|xqc_conn_on_pkt_processed|====>|conn:00000000009EBC40|size:133|pkt_type:RETRY|pkt_num:0|frame:|recv_time:1642157245008905|
[2022/01/14 10:47:25 009059] [packet_received] |scid:beea546d16caa566|xqc_conn_process_packet|pkt_pns:0|pkt_type:3|pkt_num:0|len:133|frame_flag:|
[2022/01/14 10:47:25 009078] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:IDLE|expire:1642157255008905|now:1642157245008905|interv:10000000|
[2022/01/14 10:47:25 009097] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:IDLE|expire:1642157255008905|interv:10000000|
[2022/01/14 10:47:25 009143] [debug] |xqc_engine_main_logic|
[2022/01/14 10:47:25 009192] [debug] |scid:beea546d16caa566|xqc_engine_main_logic|ticking|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:WAIT_WAKEUP TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157245009190|
[2022/01/14 10:47:25 009199] [debug] |scid:beea546d16caa566|xqc_engine_process_conn|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:WAIT_WAKEUP TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157245009198|
[2022/01/14 10:47:25 009207] [debug] |scid:beea546d16caa566|xqc_conn_next_wakeup_time|wakeup_time:1642157246508303|
[2022/01/14 10:47:26 510795] [debug] |xqc_engine_main_logic|
[2022/01/14 10:47:26 510882] [debug] |scid:beea546d16caa566|xqc_engine_main_logic|ticking|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157246510875|
[2022/01/14 10:47:26 510908] [debug] |scid:beea546d16caa566|xqc_engine_process_conn|conn:00000000009EBC40|state:C_INITIAL_SENT|flag:TICKING UPPER_CONN_EXIST ADDR_VALIDATED |now:1642157246510906|
[2022/01/14 10:47:26 510929] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_expire|timer expired|type:LOSS_DETECTION|expire_time:1642157246508303|now:1642157246510906|
[2022/01/14 10:47:26 510950] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_expire|expired|type:LOSS_DETECTION|expire_time:1642157246508303|
[2022/01/14 10:47:26 510970] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|loss_detection_timeout|
[2022/01/14 10:47:26 510989] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|send Probe pkts|conn:00000000009EBC40|bytes_in_flight:2400|
[2022/01/14 10:47:26 511008] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 2400|
[2022/01/14 10:47:26 511027] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:26 511047] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:26 511066] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|send two ack-eliciting pkts|pns:0|
[2022/01/14 10:47:26 511088] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:47:26 511197] [debug] |scid:beea546d16caa566|xqc_conn_send_one_or_two_ack_elicit_pkts|conn:00000000009EBC40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|
[2022/01/14 10:47:26 511239] [debug] |scid:beea546d16caa566|xqc_send_ctl_loss_detection_timeout|xqc_send_ctl_set_loss_detection_timer|PTO|conn:00000000009EBC40|pto_count:2
[2022/01/14 10:47:26 511259] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 1200|
[2022/01/14 10:47:26 511277] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:26 511295] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:26 511313] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157248008303|now:1642157246511258|interv:1497045|
[2022/01/14 10:47:26 511364] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157248008303|interv:1497045|
[2022/01/14 10:47:26 511397] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157248008303|now:1642157246511258|interval:1497045|pto_count:2|srtt:250000
[2022/01/14 10:47:26 511440] [debug] |scid:beea546d16caa566|xqc_conn_transmit_pto_probe_packets|conn:00000000009EBC40|pkt_num:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:47:26 511603] [datagrams_sent] |scid:beea546d16caa566|xqc_send|size:1216|
[2022/01/14 10:47:26 511650] [info] |scid:beea546d16caa566|xqc_send_packet_with_pn|<==|conn:00000000009EBC40|pkt_num:3|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:1200|now:1642157246511536|
[2022/01/14 10:47:26 511685] [packet_sent] |scid:beea546d16caa566|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:3|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:47:26 511717] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|conn:00000000009EBC40|pkt_num:3|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:47:26 511751] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|inflight:1200|applimit:0|
[2022/01/14 10:47:26 511797] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 2400|
[2022/01/14 10:47:26 511827] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:26 511857] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:26 511886] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157248511796|now:1642157246511796|interv:2000000|
[2022/01/14 10:47:26 511916] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157248511796|interv:2000000|
[2022/01/14 10:47:26 511947] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157248511796|now:1642157246511796|interval:2000000|pto_count:2|srtt:250000
[2022/01/14 10:47:26 512005] [debug] |scid:beea546d16caa566|xqc_conn_transmit_pto_probe_packets|conn:00000000009EBC40|pkt_num:1|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |
[2022/01/14 10:47:26 512144] [datagrams_sent] |scid:beea546d16caa566|xqc_send|size:1216|
[2022/01/14 10:47:26 512193] [info] |scid:beea546d16caa566|xqc_send_packet_with_pn|<==|conn:00000000009EBC40|pkt_num:4|size:1200|sent:1216|pkt_type:INIT|frame:PADDING CRYPTO |inflight:2400|now:1642157246512103|
[2022/01/14 10:47:26 512228] [packet_sent] |scid:beea546d16caa566|xqc_send_packet_with_pn|pkt_pns:0|pkt_type:0|pkt_num:4|size:1200|frame_flag:PADDING CRYPTO |
[2022/01/14 10:47:26 512263] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|conn:00000000009EBC40|pkt_num:4|origin_pktnum:0|size:1200|pkt_type:INIT|frame:PADDING CRYPTO |conn_state:C_INITIAL_SENT|po_in_flight:0|
[2022/01/14 10:47:26 512296] [debug] |scid:beea546d16caa566|xqc_send_ctl_on_packet_sent|inflight:2400|applimit:0|
[2022/01/14 10:47:26 512328] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 0, unacked: 3600|
[2022/01/14 10:47:26 512358] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 1, unacked: 0|
[2022/01/14 10:47:26 512388] [debug] |scid:beea546d16caa566|xqc_send_ctl_get_pto_time_and_space|conn:00000000009EBC40|PNS: 2, unacked: 0|
[2022/01/14 10:47:26 512417] [debug] |scid:beea546d16caa566|xqc_send_ctl_timer_set|type:LOSS_DETECTION|expire:1642157248512327|now:1642157246512327|interv:2000000|
[2022/01/14 10:47:26 512447] [loss_timer_updated] |scid:beea546d16caa566|xqc_send_ctl_timer_set|set|type:LOSS_DETECTION|expire:1642157248512327|interv:2000000|
[2022/01/14 10:47:26 512512] [debug] |scid:beea546d16caa566|xqc_send_ctl_set_loss_detection_timer|xqc_send_ctl_timer_set|update|PTO|XQC_TIMER_LOSS_DETECTION|conn:00000000009EBC40|expire:1642157248512327|now:1642157246512327|interval:2000000|pto_count:2|srtt:250000
[2022/01/14 10:47:26 512551] [debug] |scid:beea546d16caa566|xqc_conn_next_wakeup_time|wakeup_time:1642157248512327|