ATS is retransmitting a frame even though ATS knows the packet that carried the
original frame is acked.
```
[Sep 17 19:46:45.234] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] |
CRYPTO size=127 offset=0 data_len=123
[Sep 17 19:46:45.234] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] | ACK
size=5 largest_acked=0 delay=43 block_count=0 first_ack_block=0
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1151
(_state_commo> (quic_net) [4c01b675-bb43ef9c] [TX]
INITIAL packet #0 size=193
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:335
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[INITIAL] Handshake retransmission alarm will be set
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:371
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[INITIAL] Loss detection alarm has been set to 400ms
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] |
CRYPTO size=1013 offset=0 data_len=1009
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1151
(_state_commo> (quic_net) [4c01b675-bb43ef9c] [TX]
HANDSHAKE packet #0 size=1073
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:335
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Handshake retransmission alarm will be set
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:371
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Loss detection alarm has been set to 400ms
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] |
CRYPTO size=1114 offset=1009 data_len=1109
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1151
(_state_commo> (quic_net) [4c01b675-bb43ef9c] [TX]
HANDSHAKE packet #1 size=1174
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:335
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Handshake retransmission alarm will be set
[Sep 17 19:46:45.235] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:371
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Loss detection alarm has been set to 400ms
[Sep 17 19:46:45.648] {0x7f5c6e4dd700} DEBUG: <QUICNetVConnection.cc:420
(retransmit_pa> (quic_net) [4c01b675-bb43ef9c] Retransmit
HANDSHAKE packet #0
[Sep 17 19:46:45.649] {0x7f5c6e4dd700} DEBUG: <QUICNetVConnection.cc:420
(retransmit_pa> (quic_net) [4c01b675-bb43ef9c] Retransmit
HANDSHAKE packet #1
[Sep 17 19:46:45.649] {0x7f5c6e4dd700} DEBUG: <QUICCongestionController.cc:108
(on_pack> (quic_cc) [4c01b675-bb43ef9c] window: 7300
bytes: 177 ssthresh: 7300 packet lost, window changed
[Sep 17 19:46:45.649] {0x7f5c6e4dd700} DEBUG: <QUICLossDetector.cc:405
(_on_loss_detect> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Unacked packets 0 (retransmittable 0, includes 0 handshake packets)
[Sep 17 19:46:45.649] {0x7f5c6e4dd700} DEBUG: <QUICLossDetector.cc:317
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Loss detection alarm has been unset
[Sep 17 19:46:45.655] {0x7f5c6e6de700} DEBUG: <QUICNetVConnection.cc:420
(retransmit_pa> (quic_net) [4c01b675-bb43ef9c] Retransmit
INITIAL packet #0
[Sep 17 19:46:45.655] {0x7f5c6e6de700} DEBUG: <QUICLossDetector.cc:405
(_on_loss_detect> (quic_loss_detector) [4c01b675-bb43ef9c]
[INITIAL] Unacked packets 0 (retransmittable 0, includes 0 handshake packets)
[Sep 17 19:46:45.655] {0x7f5c6e6de700} DEBUG: <QUICLossDetector.cc:317
(_set_loss_detec> (quic_loss_detector) [4c01b675-bb43ef9c]
[INITIAL] Loss detection alarm has been unset
[Sep 17 19:46:45.720] {0x7f5c6ad4d700} DEBUG: <QUICPacketHandler.cc:220
(_recv_packet)> (quic_sec) [4c01b675-deb3df54] recv LH
packet from x.x.x.x:10276 size=1252
[Sep 17 19:46:45.722] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1572
(_dequeue_rec> (quic_net) [4c01b675-bb43ef9c] [RX]
INITIAL packet #1 size=1252
[Sep 17 19:46:45.722] {0x7f5c6cec3700} DEBUG: <QUICFrameDispatcher.cc:71
(receive_frame> (quic_net) [4c01b675-bb43ef9c] [RX] |
CRYPTO size=307 offset=0 data_len=303
[Sep 17 19:46:45.725] {0x7f5c6ad4d700} DEBUG: <QUICPacketHandler.cc:220
(_recv_packet)> (quic_sec) [4c01b675-bb43ef9c] recv LH
packet from x.x.x.x:10276 size=66
[Sep 17 19:46:45.732] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1572
(_dequeue_rec> (quic_net) [4c01b675-bb43ef9c] [RX]
INITIAL packet #2 size=66
[Sep 17 19:46:45.732] {0x7f5c6cec3700} DEBUG: <QUICFrameDispatcher.cc:71
(receive_frame> (quic_net) [4c01b675-bb43ef9c] [RX] | ACK
size=5 largest_acked=0 delay=0 block_count=0 first_ack_block=0
[Sep 17 19:46:45.732] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:250
(_on_ack_receive> (quic_loss_detector) [4c01b675-bb43ef9c]
[INITIAL] Unacked packets 0 (retransmittable 0, includes 0 handshake packets)
[Sep 17 19:46:45.787] {0x7f5c6ad4d700} DEBUG: <QUICPacketHandler.cc:220
(_recv_packet)> (quic_sec) [4c01b675-bb43ef9c] recv LH
packet from x.x.x.x:10276 size=120
[Sep 17 19:46:45.787] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1572
(_dequeue_rec> (quic_net) [4c01b675-bb43ef9c] [RX]
HANDSHAKE packet #0 size=120
[Sep 17 19:46:45.787] {0x7f5c6cec3700} DEBUG: <QUICFrameDispatcher.cc:71
(receive_frame> (quic_net) [4c01b675-bb43ef9c] [RX] | ACK
size=5 largest_acked=1 delay=0 block_count=0 first_ack_block=1
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICLossDetector.cc:250
(_on_ack_receive> (quic_loss_detector) [4c01b675-bb43ef9c]
[HANDSHAKE] Unacked packets 0 (retransmittable 0, includes 0 handshake packets)
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICFrameDispatcher.cc:71
(receive_frame> (quic_net) [4c01b675-bb43ef9c] [RX] |
CRYPTO size=55 offset=0 data_len=52
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:98 (msg_cb)>
(quic_tls) HANDSHAKE (22), FINISHED (20)
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:163 (key_cb)>
(vv_quic_crypto) client_application_traffic
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:177 (key_cb)>
(vv_quic_crypto)
secret=29e9cbe42c57841cb1f53f902b95e7be4f4874c708def6ed447aa92bafc4ca3f000f3d7fdcab262f8f33d9eff070f801
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:179 (key_cb)>
(vv_quic_crypto)
key=80c3b5085da2f3c15dcfbb895966e91bc7a1717969a4461be91a759c531d5fa3
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:181 (key_cb)>
(vv_quic_crypto) iv=ee521631d3f2e3dc263b6536
[Sep 17 19:46:45.788] {0x7f5c6cec3700} DEBUG: <QUICTLS_openssl.cc:183 (key_cb)>
(vv_quic_crypto)
pn=04537c015be2dbeaf3f27dffdd0798791ffc3b8c5ce4a5126a2eadebd6ffdf89
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1506
(_init_flow_c> (quic_flow_ctrl) [4c01b675-bb43ef9c] [LOCAL]
0/65536
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1508
(_init_flow_c> (quic_flow_ctrl) [4c01b675-bb43ef9c] [REMOTE]
0/1048576
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <HQSessionAccept.cc:56 (accept)>
(hq) [4c01b675-bb43ef9c] accepted
connection from x.x.x.x:10276 transport type = 6
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1751
(_switch_to_e> (quic_net) [4c01b675-bb43ef9c] Enter
state_connection_established
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1752
(_switch_to_e> (quic_net) [4c01b675-bb43ef9c] Negotiated
cipher suite: TLS_AES_256_GCM_SHA384
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICAltConnectionManager.cc:77
(_update_> (quic_alt_con) [4c01b675-bb43ef9c]
alt-cid=de7c916aacaeb3ebfb0879ce8f29cb9a6509
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICAltConnectionManager.cc:77
(_update_> (quic_alt_con) [4c01b675-bb43ef9c]
alt-cid=affe93cd86822b16bc43d964c2d1c821a057
[Sep 17 19:46:45.789] {0x7f5c6cec3700} DEBUG: <QUICAltConnectionManager.cc:77
(_update_> (quic_alt_con) [4c01b675-bb43ef9c]
alt-cid=3c9d6ea7c5000a4f33e728747d9b60c538fc
[Sep 17 19:46:45.803] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] |
CRYPTO size=127 (retransmission)
[Sep 17 19:46:45.803] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1238
(_store_frame> (quic_net) [4c01b675-bb43ef9c] [TX] | ACK
size=6 largest_acked=2 delay=8863 block_count=0 first_ack_block=1
[Sep 17 19:46:45.803] {0x7f5c6cec3700} DEBUG: <QUICNetVConnection.cc:1151
(_state_commo> (quic_net) [4c01b675-bb43ef9c] [TX]
INITIAL packet #1 size=194
```
Because the retransmission of packets is scheduled when ATS detects packet loss
and it won't be cancelled, the packets will be retransmitted even if ATS
receive delayed ACK for the packet.
The retransmitted frames would be dropped on the peer so it won't be a problem,
but not sure whether we have to do this retransmission.
[ Full content available at:
https://github.com/apache/trafficserver/issues/4255 ]
This message was relayed via gitbox.apache.org for [email protected]
