src/vnet/tcp/tcp_debug.h

   1 /*
   2  * Copyright (c) 2017-2019 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:
   6  *
   7  *     http://www.apache.org/licenses/LICENSE-2.0
   8  *
   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.
  14  */
  15
  16 #ifndef SRC_VNET_TCP_TCP_DEBUG_H_
  17 #define SRC_VNET_TCP_TCP_DEBUG_H_
  18
  19 #include <vlib/vlib.h>
  20
  21 #define TCP_DEBUG (1)
  22 #define TCP_DEBUG_SM (0)
  23 #define TCP_DEBUG_CC (0)
  24 #define TCP_DEBUG_CC_STAT (0)
  25 #define TCP_DEBUG_BUFFER_ALLOCATION (0)
  26
  27 #define foreach_tcp_dbg_evt             \
  28   _(INIT, "")                           \
  29   _(DEALLOC, "")                        \
  30   _(OPEN, "open")                       \
  31   _(CLOSE, "close")                     \
  32   _(BIND, "bind")                       \
  33   _(UNBIND, "unbind")                   \
  34   _(DELETE, "delete")                   \
  35   _(SYN_SENT, "SYN sent")               \
  36   _(SYNACK_SENT, "SYNACK sent")         \
  37   _(SYNACK_RCVD, "SYNACK rcvd")         \
  38   _(SYN_RXT, "SYN retransmit")          \
  39   _(FIN_SENT, "FIN sent")               \
  40   _(ACK_SENT, "ACK sent")               \
  41   _(DUPACK_SENT, "DUPACK sent")         \
  42   _(RST_SENT, "RST sent")               \
  43   _(SYN_RCVD, "SYN rcvd")               \
  44   _(ACK_RCVD, "ACK rcvd")               \
  45   _(DUPACK_RCVD, "DUPACK rcvd")         \
  46   _(FIN_RCVD, "FIN rcvd")               \
  47   _(RST_RCVD, "RST rcvd")               \
  48   _(STATE_CHANGE, "state change")       \
  49   _(PKTIZE, "packetize")                \
  50   _(INPUT, "in")                        \
  51   _(SND_WND, "snd_wnd update")          \
  52   _(OUTPUT, "output")                   \
  53   _(TIMER_POP, "timer pop")             \
  54   _(CC_RTX, "retransmit")               \
  55   _(CC_EVT, "cc event")                 \
  56   _(CC_PACK, "cc partial ack")          \
  57   _(CC_STAT, "cc stats")                \
  58   _(CC_RTO_STAT, "cc rto stats")        \
  59   _(CC_SCOREBOARD, "scoreboard stats")  \
  60   _(CC_SACKS, "snd sacks stats")        \
  61   _(CC_INPUT, "ooo data delivered")     \
  62   _(SEG_INVALID, "invalid segment")     \
  63   _(PAWS_FAIL, "failed paws check")     \
  64   _(ACK_RCV_ERR, "invalid ack")         \
  65   _(RCV_WND_SHRUNK, "shrunk rcv_wnd")   \
  66
  67 typedef enum _tcp_dbg
  68 {
  69 #define _(sym, str) TCP_DBG_##sym,
  70   foreach_tcp_dbg_evt
  71 #undef _
  72 } tcp_dbg_e;
  73
  74 typedef enum _tcp_dbg_evt
  75 {
  76 #define _(sym, str) TCP_EVT_##sym,
  77   foreach_tcp_dbg_evt
  78 #undef _
  79 } tcp_dbg_evt_e;
  80
  81 #if TCP_DEBUG
  82
  83 #define TRANSPORT_DEBUG (1)
  84
  85 /*
  86  * Infra and evt track setup
  87  */
  88
  89 #define TCP_DBG(_fmt, _args...) clib_warning (_fmt, ##_args)
  90
  91 #define DECLARE_ETD(_tc, _e, _size)                                     \
  92   struct                                                                \
  93   {                                                                     \
  94     u32 data[_size];                                                    \
  95   } * ed;                                                               \
  96   ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main,                    \
  97                         _e, _tc->c_elog_track)
  98
  99 #define TCP_DBG_IP_TAG_LCL(_tc)                                         \
 100 {                                                                       \
 101   if (_tc->c_is_ip4)                                                    \
 102     {                                                                   \
 103       ELOG_TYPE_DECLARE (_e) =                                          \
 104       {                                                                 \
 105         .format = "lcl: %d.%d.%d.%d:%d",                                \
 106         .format_args = "i4i4i4i4i4",                                    \
 107       };                                                                \
 108       DECLARE_ETD(_tc, _e, 5);                                          \
 109       ed->data[0] = _tc->c_lcl_ip.ip4.as_u8[0];                         \
 110       ed->data[1] = _tc->c_lcl_ip.ip4.as_u8[1];                         \
 111       ed->data[2] = _tc->c_lcl_ip.ip4.as_u8[2];                         \
 112       ed->data[3] = _tc->c_lcl_ip.ip4.as_u8[3];                         \
 113       ed->data[4] = clib_net_to_host_u16(_tc->c_lcl_port);              \
 114     }                                                                   \
 115 }
 116
 117 #define TCP_DBG_IP_TAG_RMT(_tc)                                         \
 118 {                                                                       \
 119   if (_tc->c_is_ip4)                                                    \
 120     {                                                                   \
 121       ELOG_TYPE_DECLARE (_e) =                                          \
 122       {                                                                 \
 123         .format = "rmt: %d.%d.%d.%d:%d",                                \
 124         .format_args = "i4i4i4i4i4",                                    \
 125       };                                                                \
 126       DECLARE_ETD(_tc, _e, 5);                                          \
 127       ed->data[0] = _tc->c_rmt_ip.ip4.as_u8[0];                         \
 128       ed->data[1] = _tc->c_rmt_ip.ip4.as_u8[1];                         \
 129       ed->data[2] = _tc->c_rmt_ip.ip4.as_u8[2];                         \
 130       ed->data[3] = _tc->c_rmt_ip.ip4.as_u8[3];                         \
 131       ed->data[4] = clib_net_to_host_u16(_tc->c_rmt_port);              \
 132     }                                                                   \
 133 }
 134
 135 #define TCP_EVT_INIT_HANDLER(_tc, _is_l, ...)                           \
 136 {                                                                       \
 137   char *_fmt = _is_l ? "l[%d].%d:%d%c" : "[%d].%d:%d->.%d:%d%c";        \
 138   if (_tc->c_is_ip4)                                                    \
 139     {                                                                   \
 140       _tc->c_elog_track.name =                                          \
 141         (char *) format (0, _fmt, _tc->c_thread_index,                  \
 142                          _tc->c_lcl_ip.ip4.as_u8[3],                    \
 143                          clib_net_to_host_u16(_tc->c_lcl_port),         \
 144                          _tc->c_rmt_ip.ip4.as_u8[3],                    \
 145                          clib_net_to_host_u16(_tc->c_rmt_port), 0);     \
 146     }                                                                   \
 147   else                                                                  \
 148       _tc->c_elog_track.name =                                          \
 149         (char *) format (0, _fmt, _tc->c_thread_index,                  \
 150                          _tc->c_lcl_ip.ip6.as_u8[15],                   \
 151                          clib_net_to_host_u16(_tc->c_lcl_port),         \
 152                          _tc->c_rmt_ip.ip6.as_u8[15],                   \
 153                          clib_net_to_host_u16(_tc->c_rmt_port), 0);     \
 154   elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
 155   TCP_DBG_IP_TAG_LCL(_tc);                                              \
 156   TCP_DBG_IP_TAG_RMT(_tc);                                              \
 157 }
 158
 159 #define TCP_EVT_DEALLOC_HANDLER(_tc, ...)                               \
 160 {                                                                       \
 161   vec_free (_tc->c_elog_track.name);                                    \
 162 }
 163
 164 #define TCP_EVT_OPEN_HANDLER(_tc, ...)                                  \
 165 {                                                                       \
 166   TCP_EVT_INIT_HANDLER(_tc, 0);                                         \
 167   ELOG_TYPE_DECLARE (_e) =                                              \
 168   {                                                                     \
 169     .format = "open: index %d",                                         \
 170     .format_args = "i4",                                                \
 171   };                                                                    \
 172   DECLARE_ETD(_tc, _e, 1);                                              \
 173   ed->data[0] = _tc->c_c_index;                                         \
 174 }
 175
 176 #define TCP_EVT_CLOSE_HANDLER(_tc, ...)                                 \
 177 {                                                                       \
 178   ELOG_TYPE_DECLARE (_e) =                                              \
 179   {                                                                     \
 180     .format = "close: cidx %d",                                         \
 181     .format_args = "i4",                                                \
 182   };                                                                    \
 183   DECLARE_ETD(_tc, _e, 1);                                              \
 184   ed->data[0] = _tc->c_c_index;                                         \
 185 }
 186
 187 #define TCP_EVT_BIND_HANDLER(_tc, ...)                                  \
 188 {                                                                       \
 189   TCP_EVT_INIT_HANDLER(_tc, 1);                                         \
 190   ELOG_TYPE_DECLARE (_e) =                                              \
 191   {                                                                     \
 192     .format = "bind: listener %d",                                      \
 193   };                                                                    \
 194   DECLARE_ETD(_tc, _e, 1);                                              \
 195   ed->data[0] = _tc->c_c_index;                                         \
 196 }
 197
 198 #define TCP_EVT_SYN_RCVD_HANDLER(_tc,_init, ...)                        \
 199 {                                                                       \
 200   if (_init)                                                            \
 201     TCP_EVT_INIT_HANDLER(_tc, 0);                                       \
 202   ELOG_TYPE_DECLARE (_e) =                                              \
 203   {                                                                     \
 204     .format = "syn-rx: cidx %u sidx %u irs %u",                         \
 205     .format_args = "i4i4i4",                                            \
 206   };                                                                    \
 207   DECLARE_ETD(_tc, _e, 3);                                              \
 208   ed->data[0] = _tc->c_c_index;                                         \
 209   ed->data[1] = _tc->c_s_index;                                         \
 210   ed->data[2] = _tc->irs;                                               \
 211   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 212 }
 213
 214 #define TCP_EVT_UNBIND_HANDLER(_tc, ...)                                \
 215 {                                                                       \
 216   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 217   ELOG_TYPE_DECLARE (_e) =                                              \
 218   {                                                                     \
 219     .format = "unbind: listener %d",                                    \
 220   };                                                                    \
 221   DECLARE_ETD(_tc, _e, 1);                                              \
 222   ed->data[0] = _tc->c_c_index;                                         \
 223   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 224 }
 225
 226 #define TCP_EVT_DELETE_HANDLER(_tc, ...)                                \
 227 {                                                                       \
 228   ELOG_TYPE_DECLARE (_e) =                                              \
 229   {                                                                     \
 230     .format = "delete: cidx %d sidx %d",                                \
 231     .format_args = "i4i4",                                              \
 232   };                                                                    \
 233   DECLARE_ETD(_tc, _e, 2);                                              \
 234   ed->data[0] = _tc->c_c_index;                                         \
 235   ed->data[1] = _tc->c_s_index;                                         \
 236   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 237 }
 238
 239 #define CONCAT_HELPER(_a, _b) _a##_b
 240 #define CC(_a, _b) CONCAT_HELPER(_a, _b)
 241 #define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
 242 #else
 243 #define TCP_EVT_DBG(_evt, _args...)
 244 #define TCP_DBG(_fmt, _args...)
 245 #endif
 246
 247 /*
 248  * State machine
 249  */
 250 #if TCP_DEBUG_SM
 251
 252 #define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)                          \
 253 {                                                                       \
 254   ELOG_TYPE_DECLARE (_e) =                                              \
 255   {                                                                     \
 256     .format = "state: %s",                                              \
 257     .format_args = "t4",                                                \
 258     .n_enum_strings = 11,                                               \
 259     .enum_strings = {                                                   \
 260       "closed",                                                         \
 261       "listen",                                                         \
 262       "syn-sent",                                                       \
 263       "syn-rcvd",                                                       \
 264       "established",                                                    \
 265       "close_wait",                                                     \
 266       "fin-wait-1",                                                     \
 267       "last-ack",                                                       \
 268       "closing",                                                        \
 269       "fin-wait-2",                                                     \
 270       "time-wait",                                                      \
 271     },                                                                  \
 272   };                                                                    \
 273   DECLARE_ETD(_tc, _e, 1);                                              \
 274   ed->data[0] = _tc->state;                                             \
 275 }
 276
 277 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)                              \
 278 {                                                                       \
 279   ELOG_TYPE_DECLARE (_e) =                                              \
 280   {                                                                     \
 281     .format = "syn-tx: iss %u snd_una %u snd_una_max %u snd_nxt %u",    \
 282     .format_args = "i4i4i4i4",                                          \
 283   };                                                                    \
 284   DECLARE_ETD(_tc, _e, 4);                                              \
 285   ed->data[0] = _tc->iss;                                               \
 286   ed->data[1] = _tc->snd_una - _tc->iss;                                \
 287   ed->data[2] = _tc->snd_una_max - _tc->iss;                            \
 288   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 289   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 290 }
 291
 292 #define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...)                           \
 293 {                                                                       \
 294   ELOG_TYPE_DECLARE (_e) =                                              \
 295   {                                                                     \
 296     .format = "synack-tx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
 297     .format_args = "i4i4i4i4i4",                                        \
 298   };                                                                    \
 299   DECLARE_ETD(_tc, _e, 5);                                              \
 300   ed->data[0] = _tc->iss;                                               \
 301   ed->data[1] = _tc->irs;                                               \
 302   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 303   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 304   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 305 }
 306
 307 #define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...)                           \
 308 {                                                                       \
 309   ELOG_TYPE_DECLARE (_e) =                                              \
 310   {                                                                     \
 311     .format = "synack-rx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
 312     .format_args = "i4i4i4i4i4",                                        \
 313   };                                                                    \
 314   DECLARE_ETD(_tc, _e, 5);                                              \
 315   ed->data[0] = _tc->iss;                                               \
 316   ed->data[1] = _tc->irs;                                               \
 317   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 318   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 319   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 320   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 321 }
 322
 323 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)                              \
 324 {                                                                       \
 325   ELOG_TYPE_DECLARE (_e) =                                              \
 326   {                                                                     \
 327     .format = "fin-tx: snd_nxt %d rcv_nxt %d",                          \
 328     .format_args = "i4i4",                                              \
 329   };                                                                    \
 330   DECLARE_ETD(_tc, _e, 2);                                              \
 331   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 332   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 333 }
 334
 335 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)                              \
 336 {                                                                       \
 337 if (_tc)                                                                \
 338   {                                                                     \
 339     ELOG_TYPE_DECLARE (_e) =                                            \
 340     {                                                                   \
 341       .format = "rst-tx: snd_nxt %d rcv_nxt %d",                        \
 342       .format_args = "i4i4",                                            \
 343     };                                                                  \
 344     DECLARE_ETD(_tc, _e, 2);                                            \
 345     ed->data[0] = _tc->snd_nxt - _tc->iss;                              \
 346     ed->data[1] = _tc->rcv_nxt - _tc->irs;                              \
 347     TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                  \
 348   }                                                                     \
 349 }
 350
 351 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)                              \
 352 {                                                                       \
 353   ELOG_TYPE_DECLARE (_e) =                                              \
 354   {                                                                     \
 355     .format = "fin-rx: snd_nxt %d rcv_nxt %d",                          \
 356     .format_args = "i4i4",                                              \
 357   };                                                                    \
 358   DECLARE_ETD(_tc, _e, 2);                                              \
 359   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 360   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 361 }
 362
 363 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)                              \
 364 {                                                                       \
 365   ELOG_TYPE_DECLARE (_e) =                                              \
 366   {                                                                     \
 367     .format = "rst-rx: snd_nxt %d rcv_nxt %d",                          \
 368     .format_args = "i4i4",                                              \
 369   };                                                                    \
 370   DECLARE_ETD(_tc, _e, 2);                                              \
 371   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 372   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 373 }
 374
 375 #define TCP_EVT_SYN_RXT_HANDLER(_tc, _type, ...)                        \
 376 {                                                                       \
 377   ELOG_TYPE_DECLARE (_e) =                                              \
 378   {                                                                     \
 379     .format = "%s-rxt: iss %u irs %u snd_nxt %u rcv_nxt %u",            \
 380     .format_args = "t4i4i4i4i4",                                        \
 381     .n_enum_strings = 2,                                                \
 382     .enum_strings = {                                                   \
 383         "syn",                                                          \
 384         "synack",                                                       \
 385     },                                                                  \
 386   };                                                                    \
 387   DECLARE_ETD(_tc, _e, 5);                                              \
 388   ed->data[0] = _type;                                                  \
 389   ed->data[1] = _tc->iss;                                               \
 390   ed->data[2] = _tc->irs;                                               \
 391   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 392   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 393 }
 394
 395 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
 396 {                                                                       \
 397   tcp_connection_t *_tc;                                                \
 398   if (_timer_id == TCP_TIMER_RETRANSMIT_SYN                             \
 399       || _timer_id == TCP_TIMER_ESTABLISH_AO)                           \
 400     {                                                                   \
 401       _tc = tcp_half_open_connection_get (_tc_index);                   \
 402     }                                                                   \
 403   else                                                                  \
 404     {                                                                   \
 405       u32 _thread_index = vlib_get_thread_index ();                     \
 406       _tc = tcp_connection_get (_tc_index, _thread_index);              \
 407     }                                                                   \
 408   ELOG_TYPE_DECLARE (_e) =                                              \
 409   {                                                                     \
 410     .format = "timer-pop: %s cidx %u sidx %u",                          \
 411     .format_args = "t4i4i4",                                            \
 412     .n_enum_strings = 8,                                                \
 413     .enum_strings = {                                                   \
 414       "retransmit",                                                     \
 415       "delack",                                                         \
 416       "persist",                                                        \
 417       "keep",                                                           \
 418       "waitclose",                                                      \
 419       "retransmit syn",                                                 \
 420       "establish",                                                      \
 421       "establish-ao",                                                   \
 422     },                                                                  \
 423   };                                                                    \
 424   if (_tc)                                                              \
 425     {                                                                   \
 426       DECLARE_ETD(_tc, _e, 3);                                          \
 427       ed->data[0] = _timer_id;                                          \
 428       ed->data[1] = _tc->c_c_index;                                     \
 429       ed->data[2] = _tc->c_s_index;                                     \
 430     }                                                                   \
 431   else                                                                  \
 432     {                                                                   \
 433       clib_warning ("pop %d for unexisting connection %d", _timer_id,   \
 434                     _tc_index);                                         \
 435     }                                                                   \
 436 }
 437
 438 #else
 439 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)
 440 #define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...)
 441 #define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...)
 442 #define TCP_EVT_SYN_RXT_HANDLER(_tc, ...)
 443 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)
 444 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)
 445 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)
 446 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)
 447 #define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)
 448 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)
 449 #endif
 450
 451 #if TCP_DEBUG_SM > 1
 452 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _btcp, ...)                    \
 453 {                                                                       \
 454   ELOG_TYPE_DECLARE (_e) =                                              \
 455   {                                                                     \
 456     .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u rcv_wnd %u",\
 457     .format_args = "i4i4i4i4i4",                                        \
 458   };                                                                    \
 459   DECLARE_ETD(_tc, _e, 5);                                              \
 460   ed->data[0] = _btcp.seq_number - _tc->irs;                            \
 461   ed->data[1] = _btcp.seq_end - _tc->irs;                               \
 462   ed->data[2] = _tc->rcv_las - _tc->irs;                                \
 463   ed->data[3] = _tc->rcv_nxt - _tc->irs;                                \
 464   ed->data[4] = _tc->rcv_wnd;                                           \
 465 }
 466
 467 #define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...)                 \
 468 {                                                                       \
 469   ELOG_TYPE_DECLARE (_e) =                                              \
 470   {                                                                     \
 471     .format = "paws-err: seq %u end %u tsval %u tsval_recent %u",       \
 472     .format_args = "i4i4i4i4",                                          \
 473   };                                                                    \
 474   DECLARE_ETD(_tc, _e, 4);                                              \
 475   ed->data[0] = _seq - _tc->irs;                                        \
 476   ed->data[1] = _end - _tc->irs;                                        \
 477   ed->data[2] = _tc->rcv_opts.tsval;                                    \
 478   ed->data[3] = _tc->tsval_recent;                                      \
 479 }
 480
 481 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)              \
 482 {                                                                       \
 483   ELOG_TYPE_DECLARE (_e) =                                              \
 484   {                                                                     \
 485     .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u",    \
 486     .format_args = "t4i4i4i4i4",                                        \
 487     .n_enum_strings = 3,                                                \
 488     .enum_strings = {                                                   \
 489       "invalid",                                                        \
 490       "old",                                                            \
 491       "future",                                                         \
 492     },                                                                  \
 493   };                                                                    \
 494   DECLARE_ETD(_tc, _e, 5);                                              \
 495   ed->data[0] = _type;                                                  \
 496   ed->data[1] = _ack - _tc->iss;                                        \
 497   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 498   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 499   ed->data[4] = _tc->snd_una_max - _tc->iss;                            \
 500 }
 501
 502 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)             \
 503 {                                                                       \
 504 if (_av > 0)                                                            \
 505 {                                                                       \
 506   ELOG_TYPE_DECLARE (_e) =                                              \
 507   {                                                                     \
 508     .format = "huh?: rcv_wnd %u obsd %u av %u rcv_nxt %u rcv_las %u",   \
 509     .format_args = "i4i4i4i4i4",                                        \
 510   };                                                                    \
 511   DECLARE_ETD(_tc, _e, 5);                                              \
 512   ed->data[0] = _tc->rcv_wnd;                                           \
 513   ed->data[1] = _obs;                                                   \
 514   ed->data[2] = _av;                                                    \
 515   ed->data[3] = _tc->rcv_nxt - _tc->irs;                                \
 516   ed->data[4] = _tc->rcv_las - _tc->irs;                                \
 517 }                                                                       \
 518 }
 519 #else
 520 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _btcp, ...)
 521 #define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...)
 522 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)
 523 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)
 524 #endif
 525
 526 #if TCP_DEBUG_SM > 2
 527
 528 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)                              \
 529 {                                                                       \
 530   ELOG_TYPE_DECLARE (_e) =                                              \
 531   {                                                                     \
 532     .format = "ack-tx: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u snd_wnd %u",\
 533     .format_args = "i4i4i4i4i4",                                        \
 534   };                                                                    \
 535   DECLARE_ETD(_tc, _e, 5);                                              \
 536   ed->data[0] = _tc->rcv_nxt - _tc->rcv_las;                            \
 537   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 538   ed->data[2] = _tc->rcv_wnd;                                           \
 539   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 540   ed->data[4] = _tc->snd_wnd;                                           \
 541 }
 542
 543 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)                              \
 544 {                                                                       \
 545   ELOG_TYPE_DECLARE (_e) =                                              \
 546   {                                                                     \
 547     .format = "ack-rx: %u snd_una %u snd_wnd %u cwnd %u inflight %u",   \
 548     .format_args = "i4i4i4i4i4",                                        \
 549   };                                                                    \
 550   DECLARE_ETD(_tc, _e, 5);                                              \
 551   ed->data[0] = _tc->bytes_acked;                                       \
 552   ed->data[1] = _tc->snd_una - _tc->iss;                                \
 553   ed->data[2] = _tc->snd_wnd;                                           \
 554   ed->data[3] = _tc->cwnd;                                              \
 555   ed->data[4] = tcp_flight_size(_tc);                                   \
 556 }
 557
 558 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)                                \
 559 {                                                                       \
 560   ELOG_TYPE_DECLARE (_e) =                                              \
 561   {                                                                     \
 562     .format = "tx: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
 563     .format_args = "i4i4i4i4i4",                                        \
 564   };                                                                    \
 565   DECLARE_ETD(_tc, _e, 5);                                              \
 566   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 567   ed->data[1] = _tc->snd_nxt - _tc->iss;                                \
 568   ed->data[2] = tcp_available_output_snd_space (_tc);                   \
 569   ed->data[3] = tcp_flight_size (_tc);                                  \
 570   ed->data[4] = _tc->rcv_wnd;                                           \
 571 }
 572
 573 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)          \
 574 {                                                                       \
 575   ELOG_TYPE_DECLARE (_e) =                                              \
 576   {                                                                     \
 577     .format = "in: %s len %u written %d rcv_nxt %u rcv_wnd(o) %d",      \
 578     .format_args = "t4i4i4i4i4",                                        \
 579     .n_enum_strings = 2,                                                \
 580     .enum_strings = {                                                   \
 581       "order",                                                          \
 582       "ooo",                                                            \
 583     },                                                                  \
 584   };                                                                    \
 585   DECLARE_ETD(_tc, _e, 5);                                              \
 586   ed->data[0] = _type;                                                  \
 587   ed->data[1] = _len;                                                   \
 588   ed->data[2] = _written;                                               \
 589   ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written;                   \
 590   ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);           \
 591 }
 592
 593 #else
 594 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)
 595 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)
 596 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)
 597 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)
 598 #endif
 599
 600 /*
 601  * State machine verbose
 602  */
 603 #if TCP_DEBUG_SM > 3
 604 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)                               \
 605 {                                                                       \
 606   ELOG_TYPE_DECLARE (_e) =                                              \
 607   {                                                                     \
 608     .format = "snd-wnd update: %u ",                                    \
 609     .format_args = "i4",                                                \
 610   };                                                                    \
 611   DECLARE_ETD(_tc, _e, 1);                                              \
 612   ed->data[0] = _tc->snd_wnd;                                           \
 613 }
 614
 615 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)                 \
 616 {                                                                       \
 617   ELOG_TYPE_DECLARE (_e) =                                              \
 618   {                                                                     \
 619     .format = "out: flags %x, bytes %u",                                \
 620     .format_args = "i4i4",                                              \
 621   };                                                                    \
 622   DECLARE_ETD(_tc, _e, 2);                                              \
 623   ed->data[0] = flags;                                                  \
 624   ed->data[1] = n_bytes;                                                \
 625 }
 626 #else
 627 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)
 628 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
 629 #endif
 630
 631 /*
 632  * Congestion Control
 633  */
 634
 635 #if TCP_DEBUG_CC
 636
 637 #define TCP_EVT_CC_EVT_PRINT(_tc, _sub_evt)                             \
 638 {                                                                       \
 639   ELOG_TYPE_DECLARE (_e) =                                              \
 640   {                                                                     \
 641     .format = "cc: %s snd_space %u snd_una %u out %u flight %u",        \
 642     .format_args = "t4i4i4i4i4",                                        \
 643     .n_enum_strings = 7,                                                \
 644     .enum_strings = {                                                   \
 645       "fast-rxt",                                                       \
 646       "first-rxt",                                                      \
 647       "rxt-timeout",                                                    \
 648       "recovered",                                                      \
 649       "congestion",                                                     \
 650       "undo",                                                           \
 651       "recovery",                                                       \
 652     },                                                                  \
 653   };                                                                    \
 654   DECLARE_ETD(_tc, _e, 5);                                              \
 655   ed->data[0] = _sub_evt;                                               \
 656   ed->data[1] = tcp_available_cc_snd_space (_tc);                       \
 657   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 658   ed->data[3] = tcp_bytes_out(_tc);                                     \
 659   ed->data[4] = tcp_flight_size (_tc);                                  \
 660 }
 661
 662 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)                      \
 663 {                                                                       \
 664   if (_tc->snd_una != _tc->iss)                                         \
 665     TCP_EVT_CC_STAT_PRINT (_tc);                                        \
 666   if ((_sub_evt <= 1 && TCP_DEBUG_CC > 1)                               \
 667       || (_sub_evt > 1 && TCP_DEBUG_CC > 0))                            \
 668       TCP_EVT_CC_EVT_PRINT (_tc, _sub_evt);                             \
 669 }
 670 #else
 671 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)                      \
 672
 673 #endif
 674
 675 #if TCP_DEBUG_CC > 1
 676 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)               \
 677 {                                                                       \
 678   ELOG_TYPE_DECLARE (_e) =                                              \
 679   {                                                                     \
 680     .format = "rxt: snd_nxt %u offset %u snd %u rxt %u",                \
 681     .format_args = "i4i4i4i4",                                          \
 682   };                                                                    \
 683   DECLARE_ETD(_tc, _e, 4);                                              \
 684   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 685   ed->data[1] = offset;                                                 \
 686   ed->data[2] = n_bytes;                                                \
 687   ed->data[3] = _tc->snd_rxt_bytes;                                     \
 688 }
 689
 690 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, _btcp, ...)                    \
 691 {                                                                       \
 692   ELOG_TYPE_DECLARE (_e) =                                              \
 693   {                                                                     \
 694     .format = "dack-tx: rcv_nxt %u seq %u rcv_wnd %u snd_nxt %u av_wnd %u",\
 695     .format_args = "i4i4i4i4i4",                                        \
 696   };                                                                    \
 697   DECLARE_ETD(_tc, _e, 5);                                              \
 698   ed->data[0] = _tc->rcv_nxt - _tc->irs;                                \
 699   ed->data[1] = _btcp.seq_number - _tc->irs;                            \
 700   ed->data[2] = _tc->rcv_wnd;                                           \
 701   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 702   ed->data[4] = tcp_available_snd_wnd(_tc);                             \
 703 }
 704
 705 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)                           \
 706 {                                                                       \
 707   ELOG_TYPE_DECLARE (_e) =                                              \
 708   {                                                                     \
 709     .format = "dack-rx: snd_una %u cwnd %u snd_wnd %u flight %u rcv_wnd %u",\
 710     .format_args = "i4i4i4i4i4",                                        \
 711   };                                                                    \
 712   DECLARE_ETD(_tc, _e, 5);                                              \
 713   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 714   ed->data[1] = _tc->cwnd;                                              \
 715   ed->data[2] = _tc->snd_wnd;                                           \
 716   ed->data[3] = tcp_flight_size(_tc);                                   \
 717   ed->data[4] = _tc->rcv_wnd;                                           \
 718 }
 719
 720 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)                               \
 721 {                                                                       \
 722   ELOG_TYPE_DECLARE (_e) =                                              \
 723   {                                                                     \
 724     .format = "pack: snd_una %u snd_una_max %u",                        \
 725     .format_args = "i4i4",                                              \
 726   };                                                                    \
 727   DECLARE_ETD(_tc, _e, 2);                                              \
 728   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 729   ed->data[1] = _tc->snd_una_max - _tc->iss;                            \
 730 }
 731 #define TCP_EVT_CC_SCOREBOARD_HANDLER(_tc, ...)                         \
 732 {                                                                       \
 733 if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                 \
 734   {                                                                     \
 735     ELOG_TYPE_DECLARE (_e) =                                            \
 736     {                                                                   \
 737       .format = "sb1: holes %u lost %u sacked %u high %u highrxt %u",   \
 738       .format_args = "i4i4i4i4i4",                                      \
 739     };                                                                  \
 740     DECLARE_ETD(_tc, _e, 5);                                            \
 741     ed->data[0] = pool_elts(_tc->sack_sb.holes);                        \
 742     ed->data[1] = _tc->sack_sb.lost_bytes;                              \
 743     ed->data[2] = _tc->sack_sb.sacked_bytes;                            \
 744     ed->data[3] = _tc->sack_sb.high_sacked - _tc->iss;                  \
 745     ed->data[4] = _tc->sack_sb.high_rxt - _tc->iss;                     \
 746   }                                                                     \
 747 if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                 \
 748   {                                                                     \
 749     sack_scoreboard_hole_t *hole;                                       \
 750     hole = scoreboard_first_hole (&_tc->sack_sb);                       \
 751     ELOG_TYPE_DECLARE (_e) =                                            \
 752     {                                                                   \
 753       .format = "sb2: first start: %u end %u last start %u end %u",     \
 754       .format_args = "i4i4i4i4",                                        \
 755     };                                                                  \
 756     DECLARE_ETD(_tc, _e, 4);                                            \
 757     ed->data[0] = hole ? hole->start - _tc->iss : 0;                    \
 758     ed->data[1] = hole ? hole->end - _tc->iss : 0;                      \
 759     hole = scoreboard_last_hole (&_tc->sack_sb);                        \
 760     ed->data[2] = hole ? hole->start - _tc->iss : 0;                    \
 761     ed->data[3] = hole ? hole->end - _tc->iss : 0;                      \
 762   }                                                                     \
 763 }
 764 #define TCP_EVT_CC_SACKS_HANDLER(_tc, ...)                              \
 765 {                                                                       \
 766 if (TCP_DEBUG_CC > 1)                                                   \
 767   {                                                                     \
 768     ELOG_TYPE_DECLARE (_e) =                                            \
 769     {                                                                   \
 770       .format = "sacks: blocks %u bytes %u",                            \
 771       .format_args = "i4i4",                                            \
 772     };                                                                  \
 773     DECLARE_ETD(_tc, _e, 2);                                            \
 774     ed->data[0] = vec_len (_tc->snd_sacks);                             \
 775     ed->data[1] = tcp_sack_list_bytes (_tc);                            \
 776   }                                                                     \
 777 }
 778 #define TCP_EVT_CC_INPUT_HANDLER(_tc, _len, _written, ...)              \
 779 {                                                                       \
 780   ELOG_TYPE_DECLARE (_e) =                                              \
 781   {                                                                     \
 782     .format = "cc input: len %u written %d rcv_nxt %u rcv_wnd(o) %d",   \
 783     .format_args = "i4i4i4i4",                                          \
 784   };                                                                    \
 785   DECLARE_ETD(_tc, _e, 4);                                              \
 786   ed->data[0] = _len;                                                   \
 787   ed->data[1] = _written;                                               \
 788   ed->data[2] = _tc->rcv_nxt - _tc->irs;                                \
 789   ed->data[3] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);           \
 790 }
 791 #else
 792 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
 793 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, _btcp, ...)
 794 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)
 795 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
 796 #define TCP_EVT_CC_SCOREBOARD_HANDLER(_tc, ...)
 797 #define TCP_EVT_CC_SACKS_HANDLER(_tc, ...)
 798 #define TCP_EVT_CC_INPUT_HANDLER(_tc, _len, _written, ...)
 799 #endif
 800
 801 /*
 802  * Congestion control stats
 803  */
 804 #if TCP_DEBUG_CC_STAT
 805
 806 #define STATS_INTERVAL 1
 807
 808 #define tcp_cc_time_to_print_stats(_tc)                                 \
 809   _tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()               \
 810   || tcp_in_fastrecovery (_tc)                                          \
 811
 812 #define TCP_EVT_CC_RTO_STAT_PRINT(_tc)                                  \
 813 {                                                                       \
 814   ELOG_TYPE_DECLARE (_e) =                                              \
 815   {                                                                     \
 816     .format = "rcv_stat: rto %u srtt %u mrtt-us %u rttvar %u",          \
 817     .format_args = "i4i4i4i4",                                          \
 818   };                                                                    \
 819   DECLARE_ETD(_tc, _e, 4);                                              \
 820   ed->data[0] = _tc->rto;                                               \
 821   ed->data[1] = _tc->srtt;                                              \
 822   ed->data[2] = (u32) (_tc->mrtt_us * 1e6);                             \
 823   ed->data[3] = _tc->rttvar;                                            \
 824 }
 825
 826 #define TCP_EVT_CC_RTO_STAT_HANDLER(_tc, ...)                           \
 827 {                                                                       \
 828 if (tcp_cc_time_to_print_stats (_tc))                                   \
 829 {                                                                       \
 830   TCP_EVT_CC_RTO_STAT_PRINT (_tc);                                      \
 831   _tc->c_cc_stat_tstamp = tcp_time_now ();                              \
 832 }                                                                       \
 833 }
 834
 835 #define TCP_EVT_CC_SND_STAT_PRINT(_tc)                                  \
 836 {                                                                       \
 837   ELOG_TYPE_DECLARE (_e) =                                              \
 838   {                                                                     \
 839     .format = "snd_stat: cc_space %u sacked %u lost %u out %u rxt %u",  \
 840     .format_args = "i4i4i4i4i4",                                        \
 841   };                                                                    \
 842   DECLARE_ETD(_tc, _e, 5);                                              \
 843   ed->data[0] = tcp_available_cc_snd_space (_tc);                       \
 844   ed->data[1] = _tc->sack_sb.sacked_bytes;                              \
 845   ed->data[2] = _tc->sack_sb.lost_bytes;                                \
 846   ed->data[3] = tcp_bytes_out (_tc);                                    \
 847   ed->data[3] = _tc->snd_rxt_bytes;                                     \
 848 }
 849
 850 #define TCP_EVT_CC_SND_STAT_HANDLER(_tc, ...)                           \
 851 {                                                                       \
 852 if (tcp_cc_time_to_print_stats (_tc))                                   \
 853 {                                                                       \
 854     TCP_EVT_CC_SND_STAT_PRINT(_tc);                                     \
 855     _tc->c_cc_stat_tstamp = tcp_time_now ();                            \
 856 }                                                                       \
 857 }
 858
 859 #define TCP_EVT_CC_STAT_PRINT(_tc)                                      \
 860 {                                                                       \
 861   ELOG_TYPE_DECLARE (_e) =                                              \
 862   {                                                                     \
 863     .format = "cc_stat: cwnd %u flight %u space %u ssthresh %u snd_wnd %u",\
 864     .format_args = "i4i4i4i4i4",                                        \
 865   };                                                                    \
 866   DECLARE_ETD(_tc, _e, 5);                                              \
 867   ed->data[0] = _tc->cwnd;                                              \
 868   ed->data[1] = tcp_flight_size (_tc);                                  \
 869   ed->data[2] = tcp_snd_space (_tc);                                    \
 870   ed->data[3] = _tc->ssthresh;                                          \
 871   ed->data[4] = _tc->snd_wnd;                                           \
 872   TCP_EVT_CC_RTO_STAT_PRINT (_tc);                                      \
 873   TCP_EVT_CC_SND_STAT_PRINT (_tc);                                      \
 874 }
 875
 876 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...)                               \
 877 {                                                                       \
 878 if (tcp_cc_time_to_print_stats (_tc))                                   \
 879 {                                                                       \
 880   TCP_EVT_CC_STAT_PRINT (_tc);                                          \
 881   _tc->c_cc_stat_tstamp = tcp_time_now();                               \
 882 }                                                                       \
 883 }
 884 #else
 885 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...)
 886 #define TCP_EVT_CC_STAT_PRINT(_tc)
 887 #endif
 888
 889 /*
 890  * Buffer allocation
 891  */
 892 #if TCP_DEBUG_BUFFER_ALLOCATION
 893
 894 #define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)                   \
 895 {                                                                       \
 896   static u32 *buffer_fail_counters;                                     \
 897   if (PREDICT_FALSE (buffer_fail_counters == 0))                        \
 898     {                                                                   \
 899       u32 num_threads;                                                  \
 900       vlib_thread_main_t *vtm = vlib_get_thread_main ();                \
 901       num_threads = 1 /* main thread */  + vtm->n_threads;              \
 902       vec_validate (buffer_fail_counters, num_threads - 1);             \
 903     }                                                                   \
 904   if (PREDICT_FALSE (tcp_cfg.buffer_fail_fraction != 0.0))              \
 905     {                                                                   \
 906       if (PREDICT_TRUE (buffer_fail_counters[thread_index] > 0))        \
 907         {                                                               \
 908           if ((1.0 / (f32) (buffer_fail_counters[thread_index]))        \
 909               < tcp_cfg.buffer_fail_fraction)                           \
 910             {                                                           \
 911               buffer_fail_counters[thread_index] = 0.0000001;           \
 912               return -1;                                                \
 913             }                                                           \
 914         }                                                               \
 915       buffer_fail_counters[thread_index] ++;                            \
 916     }                                                                   \
 917 }
 918 #else
 919 #define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)
 920 #endif
 921
 922 #endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
 923 /*
 924  * fd.io coding-style-patch-verification: ON
 925  *
 926  * Local Variables:
 927  * eval: (c-set-style "gnu")
 928  * End:
 929  */