2 * Copyright (c) 2017 Cisco and/or its affiliates.
3 * Licensed under the Apache License, Version 2.0 (the "License");
4 * you may not use this file except in compliance with the License.
5 * You may obtain a copy of the License at:
7 * http://www.apache.org/licenses/LICENSE-2.0
9 * Unless required by applicable law or agreed to in writing, software
10 * distributed under the License is distributed on an "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 * See the License for the specific language governing permissions and
13 * limitations under the License.
16 #ifndef SRC_VNET_TCP_TCP_DEBUG_H_
17 #define SRC_VNET_TCP_TCP_DEBUG_H_
19 #include <vlib/vlib.h>
22 #define TCP_DEBUG_SM (0)
23 #define TCP_DEBUG_CC (1)
24 #define TCP_DEBUG_CC_STAT (1)
25 #define TCP_DEBUG_SM_VERBOSE (0)
27 #define foreach_tcp_dbg_evt \
35 _(SYN_SENT, "SYN sent") \
36 _(SYN_RTX, "SYN retransmit") \
37 _(FIN_SENT, "FIN sent") \
38 _(ACK_SENT, "ACK sent") \
39 _(DUPACK_SENT, "DUPACK sent") \
40 _(RST_SENT, "RST sent") \
41 _(SYN_RCVD, "SYN rcvd") \
42 _(ACK_RCVD, "ACK rcvd") \
43 _(DUPACK_RCVD, "DUPACK rcvd") \
44 _(FIN_RCVD, "FIN rcvd") \
45 _(RST_RCVD, "RST rcvd") \
46 _(PKTIZE, "packetize") \
48 _(SND_WND, "snd_wnd update") \
50 _(TIMER_POP, "timer pop") \
51 _(CC_RTX, "retransmit") \
52 _(CC_EVT, "cc event") \
53 _(CC_PACK, "cc partial ack") \
54 _(CC_STAT, "cc stats") \
55 _(CC_RTO_STAT, "cc rto stats") \
56 _(SEG_INVALID, "invalid segment") \
57 _(PAWS_FAIL, "failed paws check") \
58 _(ACK_RCV_ERR, "invalid ack") \
59 _(RCV_WND_SHRUNK, "shrunk rcv_wnd") \
63 #define _(sym, str) TCP_DBG_##sym,
68 typedef enum _tcp_dbg_evt
70 #define _(sym, str) TCP_EVT_##sym,
77 #define TRANSPORT_DEBUG (1)
80 * Infra and evt track setup
83 #define TCP_DBG(_tc, _evt, _args...) \
86 _tmp = format(_tmp, "%U", format_tcp_connection_verbose, _tc); \
87 clib_warning("%s", _tmp); \
91 #define DECLARE_ETD(_tc, _e, _size) \
96 ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, \
97 _e, _tc->c_elog_track)
99 #define TCP_EVT_INIT_HANDLER(_tc, _fmt, ...) \
101 _tc->c_elog_track.name = \
102 (char *) format (0, _fmt, _tc->c_c_index, 0); \
103 elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
106 #define TCP_EVT_DEALLOC_HANDLER(_tc, ...) \
108 vec_free (_tc->c_elog_track.name); \
111 #define TCP_EVT_OPEN_HANDLER(_tc, ...) \
113 TCP_EVT_INIT_HANDLER(_tc, "s%d%c"); \
114 ELOG_TYPE_DECLARE (_e) = \
116 .format = "open: index %d", \
117 .format_args = "i4", \
119 DECLARE_ETD(_tc, _e, 1); \
120 ed->data[0] = _tc->c_c_index; \
123 #define TCP_EVT_CLOSE_HANDLER(_tc, ...) \
125 ELOG_TYPE_DECLARE (_e) = \
127 .format = "close: %d", \
128 .format_args = "i4", \
130 DECLARE_ETD(_tc, _e, 1); \
131 ed->data[0] = _tc->c_c_index; \
134 #define TCP_EVT_BIND_HANDLER(_tc, ...) \
136 TCP_EVT_INIT_HANDLER(_tc, "l%d%c"); \
137 ELOG_TYPE_DECLARE (_e) = \
139 .format = "bind: listener %d", \
141 DECLARE_ETD(_tc, _e, 1); \
142 ed->data[0] = _tc->c_c_index; \
145 #define TCP_EVT_UNBIND_HANDLER(_tc, ...) \
147 TCP_EVT_DEALLOC_HANDLER(_tc); \
148 ELOG_TYPE_DECLARE (_e) = \
150 .format = "unbind: listener %d", \
152 DECLARE_ETD(_tc, _e, 1); \
153 ed->data[0] = _tc->c_c_index; \
154 TCP_EVT_DEALLOC_HANDLER(_tc); \
157 #define TCP_EVT_DELETE_HANDLER(_tc, ...) \
159 ELOG_TYPE_DECLARE (_e) = \
161 .format = "delete: %d", \
162 .format_args = "i4", \
164 DECLARE_ETD(_tc, _e, 1); \
165 ed->data[0] = _tc->c_c_index; \
166 TCP_EVT_DEALLOC_HANDLER(_tc); \
169 #define TCP_EVT_SYN_RCVD_HANDLER(_tc, ...) \
171 TCP_EVT_INIT_HANDLER(_tc, "s%d%c"); \
172 ELOG_TYPE_DECLARE (_e) = \
174 .format = "SYNrx: irs %u", \
175 .format_args = "i4", \
177 DECLARE_ETD(_tc, _e, 1); \
178 ed->data[0] = _tc->irs; \
181 #define CONCAT_HELPER(_a, _b) _a##_b
182 #define CC(_a, _b) CONCAT_HELPER(_a, _b)
183 #define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
185 #define TCP_EVT_DBG(_evt, _args...)
193 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...) \
195 ELOG_TYPE_DECLARE (_e) = \
197 .format = "ack_tx: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u snd_wnd %u",\
198 .format_args = "i4i4i4i4i4", \
200 DECLARE_ETD(_tc, _e, 5); \
201 ed->data[0] = _tc->rcv_nxt - _tc->rcv_las; \
202 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
203 ed->data[2] = _tc->rcv_wnd; \
204 ed->data[3] = _tc->snd_nxt - _tc->iss; \
205 ed->data[4] = _tc->snd_wnd; \
208 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...) \
210 ELOG_TYPE_DECLARE (_e) = \
212 .format = "dack_tx: rcv_nxt %u rcv_wnd %u snd_nxt %u av_wnd %u snd_wnd %u",\
213 .format_args = "i4i4i4i4i4", \
215 DECLARE_ETD(_tc, _e, 5); \
216 ed->data[0] = _tc->rcv_nxt - _tc->irs; \
217 ed->data[1] = _tc->rcv_wnd; \
218 ed->data[2] = _tc->snd_nxt - _tc->iss; \
219 ed->data[3] = tcp_available_wnd(_tc); \
220 ed->data[4] = _tc->snd_wnd; \
223 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...) \
225 ELOG_TYPE_DECLARE (_e) = \
227 .format = "SYNtx: iss %u", \
228 .format_args = "i4", \
230 DECLARE_ETD(_tc, _e, 1); \
231 ed->data[0] = _tc->iss; \
234 #define TCP_EVT_SYN_RTX_HANDLER(_tc, ...) \
236 ELOG_TYPE_DECLARE (_e) = \
238 .format = "SYNrtx: iss %u", \
239 .format_args = "i4", \
241 DECLARE_ETD(_tc, _e, 1); \
242 ed->data[0] = _tc->iss; \
245 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...) \
247 ELOG_TYPE_DECLARE (_e) = \
249 .format = "FINtx: snd_nxt %d rcv_nxt %d", \
250 .format_args = "i4i4", \
252 DECLARE_ETD(_tc, _e, 2); \
253 ed->data[0] = _tc->snd_nxt - _tc->iss; \
254 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
257 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...) \
259 ELOG_TYPE_DECLARE (_e) = \
261 .format = "RSTtx: snd_nxt %d rcv_nxt %d", \
262 .format_args = "i4i4", \
264 DECLARE_ETD(_tc, _e, 2); \
265 ed->data[0] = _tc->snd_nxt - _tc->iss; \
266 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
269 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...) \
271 ELOG_TYPE_DECLARE (_e) = \
273 .format = "FINrx: snd_nxt %d rcv_nxt %d", \
274 .format_args = "i4i4", \
276 DECLARE_ETD(_tc, _e, 2); \
277 ed->data[0] = _tc->snd_nxt - _tc->iss; \
278 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
281 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...) \
283 ELOG_TYPE_DECLARE (_e) = \
285 .format = "RSTrx: snd_nxt %d rcv_nxt %d", \
286 .format_args = "i4i4", \
288 DECLARE_ETD(_tc, _e, 2); \
289 ed->data[0] = _tc->snd_nxt - _tc->iss; \
290 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
293 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...) \
295 ELOG_TYPE_DECLARE (_e) = \
297 .format = "acked: %u snd_una %u snd_wnd %u cwnd %u inflight %u", \
298 .format_args = "i4i4i4i4i4", \
300 DECLARE_ETD(_tc, _e, 5); \
301 ed->data[0] = _tc->bytes_acked; \
302 ed->data[1] = _tc->snd_una - _tc->iss; \
303 ed->data[2] = _tc->snd_wnd; \
304 ed->data[3] = _tc->cwnd; \
305 ed->data[4] = tcp_flight_size(_tc); \
308 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...) \
310 ELOG_TYPE_DECLARE (_e) = \
312 .format = "dack_rx: snd_una %u cwnd %u snd_wnd %u flight %u rcv_wnd %u",\
313 .format_args = "i4i4i4i4i4", \
315 DECLARE_ETD(_tc, _e, 5); \
316 ed->data[0] = _tc->snd_una - _tc->iss; \
317 ed->data[1] = _tc->cwnd; \
318 ed->data[2] = _tc->snd_wnd; \
319 ed->data[3] = tcp_flight_size(_tc); \
320 ed->data[4] = _tc->rcv_wnd; \
323 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...) \
325 ELOG_TYPE_DECLARE (_e) = \
327 .format = "pktize: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
328 .format_args = "i4i4i4i4i4", \
330 DECLARE_ETD(_tc, _e, 5); \
331 ed->data[0] = _tc->snd_una - _tc->iss; \
332 ed->data[1] = _tc->snd_nxt - _tc->iss; \
333 ed->data[2] = tcp_available_snd_space (_tc); \
334 ed->data[3] = tcp_flight_size (_tc); \
335 ed->data[4] = _tc->rcv_wnd; \
338 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...) \
340 ELOG_TYPE_DECLARE (_e) = \
342 .format = "in: %s len %u written %d rcv_nxt %u rcv_wnd(o) %d", \
343 .format_args = "t4i4i4i4i4", \
344 .n_enum_strings = 2, \
350 DECLARE_ETD(_tc, _e, 5); \
351 ed->data[0] = _type; \
352 ed->data[1] = _len; \
353 ed->data[2] = _written; \
354 ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written; \
355 ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las); \
358 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...) \
360 tcp_connection_t *_tc; \
361 if (_timer_id == TCP_TIMER_RETRANSMIT_SYN \
362 || _timer_id == TCP_TIMER_ESTABLISH) \
364 _tc = tcp_half_open_connection_get (_tc_index); \
368 u32 _thread_index = vlib_get_thread_index (); \
369 _tc = tcp_connection_get (_tc_index, _thread_index); \
371 ELOG_TYPE_DECLARE (_e) = \
373 .format = "TimerPop: %s (%d)", \
374 .format_args = "t4i4", \
375 .n_enum_strings = 7, \
386 DECLARE_ETD(_tc, _e, 2); \
387 ed->data[0] = _timer_id; \
388 ed->data[1] = _timer_id; \
391 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...) \
393 ELOG_TYPE_DECLARE (_e) = \
395 .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u rcv_wnd %u",\
396 .format_args = "i4i4i4i4i4", \
398 DECLARE_ETD(_tc, _e, 5); \
399 ed->data[0] = _seq - _tc->irs; \
400 ed->data[1] = _end - _tc->irs; \
401 ed->data[2] = _tc->rcv_las - _tc->irs; \
402 ed->data[3] = _tc->rcv_nxt - _tc->irs; \
403 ed->data[4] = _tc->rcv_wnd; \
406 #define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...) \
408 ELOG_TYPE_DECLARE (_e) = \
410 .format = "paws fail: seq %u end %u tsval %u tsval_recent %u", \
411 .format_args = "i4i4i4i4", \
413 DECLARE_ETD(_tc, _e, 4); \
414 ed->data[0] = _seq - _tc->irs; \
415 ed->data[1] = _end - _tc->irs; \
416 ed->data[2] = _tc->rcv_opts.tsval; \
417 ed->data[3] = _tc->tsval_recent; \
420 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...) \
422 ELOG_TYPE_DECLARE (_e) = \
424 .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u", \
425 .format_args = "t4i4i4i4i4", \
426 .n_enum_strings = 3, \
433 DECLARE_ETD(_tc, _e, 5); \
434 ed->data[0] = _type; \
435 ed->data[1] = _ack - _tc->iss; \
436 ed->data[2] = _tc->snd_una - _tc->iss; \
437 ed->data[3] = _tc->snd_nxt - _tc->iss; \
438 ed->data[4] = _tc->snd_una_max - _tc->iss; \
441 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...) \
445 ELOG_TYPE_DECLARE (_e) = \
447 .format = "huh?: rcv_wnd %u obsd %u av %u rcv_nxt %u rcv_las %u", \
448 .format_args = "i4i4i4i4i4", \
450 DECLARE_ETD(_tc, _e, 5); \
451 ed->data[0] = _tc->rcv_wnd; \
452 ed->data[1] = _obs; \
454 ed->data[3] = _tc->rcv_nxt - _tc->irs; \
455 ed->data[4] = _tc->rcv_las - _tc->irs; \
459 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)
460 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...)
461 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)
462 #define TCP_EVT_SYN_RTX_HANDLER(_tc, ...)
463 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)
464 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)
465 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)
466 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)
467 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)
468 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)
469 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)
470 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)
471 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)
472 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...)
473 #define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...)
474 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)
475 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)
479 * State machine verbose
481 #if TCP_DBG_SM_VERBOSE
482 #define TCP_EVT_SND_WND_HANDLER(_tc, ...) \
484 ELOG_TYPE_DECLARE (_e) = \
486 .format = "snd_wnd update: %u ", \
487 .format_args = "i4", \
489 DECLARE_ETD(_tc, _e, 1); \
490 ed->data[0] = _tc->snd_wnd; \
493 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...) \
495 ELOG_TYPE_DECLARE (_e) = \
497 .format = "out: flags %x, bytes %u", \
498 .format_args = "i4i4", \
500 DECLARE_ETD(_tc, _e, 2); \
501 ed->data[0] = flags; \
502 ed->data[1] = n_bytes; \
505 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)
506 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
514 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...) \
516 ELOG_TYPE_DECLARE (_e) = \
518 .format = "rxt: snd_nxt %u offset %u snd %u rxt %u", \
519 .format_args = "i4i4i4i4", \
521 DECLARE_ETD(_tc, _e, 4); \
522 ed->data[0] = _tc->snd_nxt - _tc->iss; \
523 ed->data[1] = offset; \
524 ed->data[2] = n_bytes; \
525 ed->data[3] = _tc->snd_rxt_bytes; \
528 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...) \
530 ELOG_TYPE_DECLARE (_e) = \
532 .format = "cc: %s wnd %u snd_cong %u rxt_bytes %u", \
533 .format_args = "t4i4i4i4", \
534 .n_enum_strings = 5, \
543 DECLARE_ETD(_tc, _e, 4); \
544 ed->data[0] = _sub_evt; \
545 ed->data[1] = tcp_available_snd_space (_tc); \
546 ed->data[2] = _tc->snd_congestion - _tc->iss; \
547 ed->data[3] = _tc->snd_rxt_bytes; \
550 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...) \
552 ELOG_TYPE_DECLARE (_e) = \
554 .format = "pack: snd_una %u snd_una_max %u", \
555 .format_args = "i4i4", \
557 DECLARE_ETD(_tc, _e, 2); \
558 ed->data[0] = _tc->snd_una - _tc->iss; \
559 ed->data[1] = _tc->snd_una_max - _tc->iss; \
563 * Congestion control stats
565 #if TCP_DEBUG_CC_STAT
567 #define STATS_INTERVAL 1
569 #define TCP_EVT_CC_RTO_STAT_HANDLER(_tc, ...) \
571 if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()) \
573 ELOG_TYPE_DECLARE (_e) = \
575 .format = "rto_stat: rto %u srtt %u rttvar %u ", \
576 .format_args = "i4i4i4", \
578 DECLARE_ETD(_tc, _e, 3); \
579 ed->data[0] = _tc->rto; \
580 ed->data[1] = _tc->srtt; \
581 ed->data[2] = _tc->rttvar; \
585 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...) \
587 if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()) \
589 ELOG_TYPE_DECLARE (_e) = \
591 .format = "cc_stat: cwnd %u flight %u space %u ssthresh %u snd_wnd %u",\
592 .format_args = "i4i4i4i4i4", \
594 DECLARE_ETD(_tc, _e, 5); \
595 ed->data[0] = _tc->cwnd; \
596 ed->data[1] = tcp_flight_size (_tc); \
597 ed->data[2] = tcp_snd_space (_tc); \
598 ed->data[3] = _tc->ssthresh; \
599 ed->data[4] = _tc->snd_wnd; \
600 TCP_EVT_CC_RTO_STAT_HANDLER (_tc); \
601 _tc->c_cc_stat_tstamp = tcp_time_now(); \
606 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...)
610 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
611 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)
612 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
615 #endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
617 * fd.io coding-style-patch-verification: ON
620 * eval: (c-set-style "gnu")