16 #ifndef SRC_VNET_TCP_TCP_DEBUG_H_ 17 #define SRC_VNET_TCP_TCP_DEBUG_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) 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, ...) 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; \ 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, ...)
#define foreach_tcp_dbg_evt
enum _tcp_dbg_evt tcp_dbg_evt_e