src/vnet/tcp/tcp_debug.h

   1 /*
   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:
   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: %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: irs %u",                                         \
 205     .format_args = "i4",                                                \
 206   };                                                                    \
 207   DECLARE_ETD(_tc, _e, 1);                                              \
 208   ed->data[0] = _tc->irs;                                               \
 209   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 210 }
 211
 212 #define TCP_EVT_UNBIND_HANDLER(_tc, ...)                                \
 213 {                                                                       \
 214   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 215   ELOG_TYPE_DECLARE (_e) =                                              \
 216   {                                                                     \
 217     .format = "unbind: listener %d",                                    \
 218   };                                                                    \
 219   DECLARE_ETD(_tc, _e, 1);                                              \
 220   ed->data[0] = _tc->c_c_index;                                         \
 221   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 222 }
 223
 224 #define TCP_EVT_DELETE_HANDLER(_tc, ...)                                \
 225 {                                                                       \
 226   ELOG_TYPE_DECLARE (_e) =                                              \
 227   {                                                                     \
 228     .format = "delete: %d",                                             \
 229     .format_args = "i4",                                                \
 230   };                                                                    \
 231   DECLARE_ETD(_tc, _e, 1);                                              \
 232   ed->data[0] = _tc->c_c_index;                                         \
 233   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 234 }
 235
 236 #define CONCAT_HELPER(_a, _b) _a##_b
 237 #define CC(_a, _b) CONCAT_HELPER(_a, _b)
 238 #define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
 239 #else
 240 #define TCP_EVT_DBG(_evt, _args...)
 241 #define TCP_DBG(_fmt, _args...)
 242 #endif
 243
 244 /*
 245  * State machine
 246  */
 247 #if TCP_DEBUG_SM
 248
 249 #define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)                          \
 250 {                                                                       \
 251   ELOG_TYPE_DECLARE (_e) =                                              \
 252   {                                                                     \
 253     .format = "state: %s",                                              \
 254     .format_args = "t4",                                                \
 255     .n_enum_strings = 11,                                               \
 256     .enum_strings = {                                                   \
 257       "closed",                                                         \
 258       "listen",                                                         \
 259       "syn-sent",                                                       \
 260       "syn-rcvd",                                                       \
 261       "established",                                                    \
 262       "close_wait",                                                     \
 263       "fin-wait-1",                                                     \
 264       "last-ack",                                                       \
 265       "closing",                                                        \
 266       "fin-wait-2",                                                     \
 267       "time-wait",                                                      \
 268     },                                                                  \
 269   };                                                                    \
 270   DECLARE_ETD(_tc, _e, 1);                                              \
 271   ed->data[0] = _tc->state;                                             \
 272 }
 273
 274 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)                              \
 275 {                                                                       \
 276   ELOG_TYPE_DECLARE (_e) =                                              \
 277   {                                                                     \
 278     .format = "syn-tx: iss %u snd_una %u snd_una_max %u snd_nxt %u",    \
 279     .format_args = "i4i4i4i4",                                          \
 280   };                                                                    \
 281   DECLARE_ETD(_tc, _e, 4);                                              \
 282   ed->data[0] = _tc->iss;                                               \
 283   ed->data[1] = _tc->snd_una - _tc->iss;                                \
 284   ed->data[2] = _tc->snd_una_max - _tc->iss;                            \
 285   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 286   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 287 }
 288
 289 #define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...)                           \
 290 {                                                                       \
 291   ELOG_TYPE_DECLARE (_e) =                                              \
 292   {                                                                     \
 293     .format = "synack-tx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
 294     .format_args = "i4i4i4i4i4",                                        \
 295   };                                                                    \
 296   DECLARE_ETD(_tc, _e, 5);                                              \
 297   ed->data[0] = _tc->iss;                                               \
 298   ed->data[1] = _tc->irs;                                               \
 299   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 300   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 301   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 302 }
 303
 304 #define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...)                           \
 305 {                                                                       \
 306   ELOG_TYPE_DECLARE (_e) =                                              \
 307   {                                                                     \
 308     .format = "synack-rx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
 309     .format_args = "i4i4i4i4i4",                                        \
 310   };                                                                    \
 311   DECLARE_ETD(_tc, _e, 5);                                              \
 312   ed->data[0] = _tc->iss;                                               \
 313   ed->data[1] = _tc->irs;                                               \
 314   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 315   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 316   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 317   TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                    \
 318 }
 319
 320 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)                              \
 321 {                                                                       \
 322   ELOG_TYPE_DECLARE (_e) =                                              \
 323   {                                                                     \
 324     .format = "fin-tx: snd_nxt %d rcv_nxt %d",                          \
 325     .format_args = "i4i4",                                              \
 326   };                                                                    \
 327   DECLARE_ETD(_tc, _e, 2);                                              \
 328   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 329   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 330 }
 331
 332 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)                              \
 333 {                                                                       \
 334 if (_tc)                                                                \
 335   {                                                                     \
 336     ELOG_TYPE_DECLARE (_e) =                                            \
 337     {                                                                   \
 338       .format = "rst-tx: snd_nxt %d rcv_nxt %d",                        \
 339       .format_args = "i4i4",                                            \
 340     };                                                                  \
 341     DECLARE_ETD(_tc, _e, 2);                                            \
 342     ed->data[0] = _tc->snd_nxt - _tc->iss;                              \
 343     ed->data[1] = _tc->rcv_nxt - _tc->irs;                              \
 344     TCP_EVT_STATE_CHANGE_HANDLER(_tc);                                  \
 345   }                                                                     \
 346 }
 347
 348 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)                              \
 349 {                                                                       \
 350   ELOG_TYPE_DECLARE (_e) =                                              \
 351   {                                                                     \
 352     .format = "fin-rx: snd_nxt %d rcv_nxt %d",                          \
 353     .format_args = "i4i4",                                              \
 354   };                                                                    \
 355   DECLARE_ETD(_tc, _e, 2);                                              \
 356   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 357   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 358 }
 359
 360 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)                              \
 361 {                                                                       \
 362   ELOG_TYPE_DECLARE (_e) =                                              \
 363   {                                                                     \
 364     .format = "rst-rx: snd_nxt %d rcv_nxt %d",                          \
 365     .format_args = "i4i4",                                              \
 366   };                                                                    \
 367   DECLARE_ETD(_tc, _e, 2);                                              \
 368   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 369   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 370 }
 371
 372 #define TCP_EVT_SYN_RXT_HANDLER(_tc, _type, ...)                        \
 373 {                                                                       \
 374   ELOG_TYPE_DECLARE (_e) =                                              \
 375   {                                                                     \
 376     .format = "%s-rxt: iss %u irs %u snd_nxt %u rcv_nxt %u",            \
 377     .format_args = "t4i4i4i4i4",                                        \
 378     .n_enum_strings = 2,                                                \
 379     .enum_strings = {                                                   \
 380         "syn",                                                          \
 381         "syn-ack",                                                      \
 382     },                                                                  \
 383   };                                                                    \
 384   DECLARE_ETD(_tc, _e, 5);                                              \
 385   ed->data[0] = _type;                                                  \
 386   ed->data[1] = _tc->iss;                                               \
 387   ed->data[2] = _tc->irs;                                               \
 388   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 389   ed->data[4] = _tc->rcv_nxt - _tc->irs;                                \
 390 }
 391 #else
 392 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)
 393 #define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...)
 394 #define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...)
 395 #define TCP_EVT_SYN_RXT_HANDLER(_tc, ...)
 396 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)
 397 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)
 398 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)
 399 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)
 400 #define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)
 401 #endif
 402
 403 #if TCP_DEBUG_SM > 1
 404 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _btcp, ...)                    \
 405 {                                                                       \
 406   ELOG_TYPE_DECLARE (_e) =                                              \
 407   {                                                                     \
 408     .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u rcv_wnd %u",\
 409     .format_args = "i4i4i4i4i4",                                        \
 410   };                                                                    \
 411   DECLARE_ETD(_tc, _e, 5);                                              \
 412   ed->data[0] = _btcp.seq_number - _tc->irs;                            \
 413   ed->data[1] = _btcp.seq_end - _tc->irs;                               \
 414   ed->data[2] = _tc->rcv_las - _tc->irs;                                \
 415   ed->data[3] = _tc->rcv_nxt - _tc->irs;                                \
 416   ed->data[4] = _tc->rcv_wnd;                                           \
 417 }
 418
 419 #define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...)                 \
 420 {                                                                       \
 421   ELOG_TYPE_DECLARE (_e) =                                              \
 422   {                                                                     \
 423     .format = "paws-err: seq %u end %u tsval %u tsval_recent %u",       \
 424     .format_args = "i4i4i4i4",                                          \
 425   };                                                                    \
 426   DECLARE_ETD(_tc, _e, 4);                                              \
 427   ed->data[0] = _seq - _tc->irs;                                        \
 428   ed->data[1] = _end - _tc->irs;                                        \
 429   ed->data[2] = _tc->rcv_opts.tsval;                                    \
 430   ed->data[3] = _tc->tsval_recent;                                      \
 431 }
 432
 433 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)              \
 434 {                                                                       \
 435   ELOG_TYPE_DECLARE (_e) =                                              \
 436   {                                                                     \
 437     .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u",    \
 438     .format_args = "t4i4i4i4i4",                                        \
 439     .n_enum_strings = 3,                                                \
 440     .enum_strings = {                                                   \
 441       "invalid",                                                        \
 442       "old",                                                            \
 443       "future",                                                         \
 444     },                                                                  \
 445   };                                                                    \
 446   DECLARE_ETD(_tc, _e, 5);                                              \
 447   ed->data[0] = _type;                                                  \
 448   ed->data[1] = _ack - _tc->iss;                                        \
 449   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 450   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 451   ed->data[4] = _tc->snd_una_max - _tc->iss;                            \
 452 }
 453
 454 #define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)             \
 455 {                                                                       \
 456 if (_av > 0)                                                            \
 457 {                                                                       \
 458   ELOG_TYPE_DECLARE (_e) =                                              \
 459   {                                                                     \
 460     .format = "huh?: rcv_wnd %u obsd %u av %u rcv_nxt %u rcv_las %u",   \
 461     .format_args = "i4i4i4i4i4",                                        \
 462   };                                                                    \
 463   DECLARE_ETD(_tc, _e, 5);                                              \
 464   ed->data[0] = _tc->rcv_wnd;                                           \
 465   ed->data[1] = _obs;                                                   \
 466   ed->data[2] = _av;                                                    \
 467   ed->data[3] = _tc->rcv_nxt - _tc->irs;                                \
 468   ed->data[4] = _tc->rcv_las - _tc->irs;                                \
 469 }                                                                       \
 470 }
 471 #else
 472 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _btcp, ...)
 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, ...)
 476 #endif
 477
 478 #if TCP_DEBUG_SM > 2
 479
 480 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)                              \
 481 {                                                                       \
 482   ELOG_TYPE_DECLARE (_e) =                                              \
 483   {                                                                     \
 484     .format = "ack-tx: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u snd_wnd %u",\
 485     .format_args = "i4i4i4i4i4",                                        \
 486   };                                                                    \
 487   DECLARE_ETD(_tc, _e, 5);                                              \
 488   ed->data[0] = _tc->rcv_nxt - _tc->rcv_las;                            \
 489   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 490   ed->data[2] = _tc->rcv_wnd;                                           \
 491   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 492   ed->data[4] = _tc->snd_wnd;                                           \
 493 }
 494
 495 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)                              \
 496 {                                                                       \
 497   ELOG_TYPE_DECLARE (_e) =                                              \
 498   {                                                                     \
 499     .format = "ack-rx: %u snd_una %u snd_wnd %u cwnd %u inflight %u",   \
 500     .format_args = "i4i4i4i4i4",                                        \
 501   };                                                                    \
 502   DECLARE_ETD(_tc, _e, 5);                                              \
 503   ed->data[0] = _tc->bytes_acked;                                       \
 504   ed->data[1] = _tc->snd_una - _tc->iss;                                \
 505   ed->data[2] = _tc->snd_wnd;                                           \
 506   ed->data[3] = _tc->cwnd;                                              \
 507   ed->data[4] = tcp_flight_size(_tc);                                   \
 508 }
 509
 510 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)                                \
 511 {                                                                       \
 512   ELOG_TYPE_DECLARE (_e) =                                              \
 513   {                                                                     \
 514     .format = "tx: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
 515     .format_args = "i4i4i4i4i4",                                        \
 516   };                                                                    \
 517   DECLARE_ETD(_tc, _e, 5);                                              \
 518   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 519   ed->data[1] = _tc->snd_nxt - _tc->iss;                                \
 520   ed->data[2] = tcp_available_output_snd_space (_tc);                   \
 521   ed->data[3] = tcp_flight_size (_tc);                                  \
 522   ed->data[4] = _tc->rcv_wnd;                                           \
 523 }
 524
 525 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)          \
 526 {                                                                       \
 527   ELOG_TYPE_DECLARE (_e) =                                              \
 528   {                                                                     \
 529     .format = "in: %s len %u written %d rcv_nxt %u rcv_wnd(o) %d",      \
 530     .format_args = "t4i4i4i4i4",                                        \
 531     .n_enum_strings = 2,                                                \
 532     .enum_strings = {                                                   \
 533       "order",                                                          \
 534       "ooo",                                                            \
 535     },                                                                  \
 536   };                                                                    \
 537   DECLARE_ETD(_tc, _e, 5);                                              \
 538   ed->data[0] = _type;                                                  \
 539   ed->data[1] = _len;                                                   \
 540   ed->data[2] = _written;                                               \
 541   ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written;                   \
 542   ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);           \
 543 }
 544
 545 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
 546 {                                                                       \
 547   tcp_connection_t *_tc;                                                \
 548   if (_timer_id == TCP_TIMER_RETRANSMIT_SYN                             \
 549     || _timer_id == TCP_TIMER_ESTABLISH)                                \
 550     {                                                                   \
 551       _tc = tcp_half_open_connection_get (_tc_index);                   \
 552     }                                                                   \
 553   else                                                                  \
 554     {                                                                   \
 555       u32 _thread_index = vlib_get_thread_index ();                     \
 556       _tc = tcp_connection_get (_tc_index, _thread_index);              \
 557     }                                                                   \
 558   ELOG_TYPE_DECLARE (_e) =                                              \
 559   {                                                                     \
 560     .format = "timer-pop: %s (%d)",                                     \
 561     .format_args = "t4i4",                                              \
 562     .n_enum_strings = 7,                                                \
 563     .enum_strings = {                                                   \
 564       "retransmit",                                                     \
 565       "delack",                                                         \
 566       "persist",                                                        \
 567       "keep",                                                           \
 568       "waitclose",                                                      \
 569       "retransmit syn",                                                 \
 570       "establish",                                                      \
 571     },                                                                  \
 572   };                                                                    \
 573   if (_tc)                                                              \
 574     {                                                                   \
 575       DECLARE_ETD(_tc, _e, 2);                                          \
 576       ed->data[0] = _timer_id;                                          \
 577       ed->data[1] = _timer_id;                                          \
 578     }                                                                   \
 579   else                                                                  \
 580     {                                                                   \
 581       clib_warning ("pop %d for unexisting connection %d", _timer_id,   \
 582                     _tc_index);                                         \
 583     }                                                                   \
 584 }
 585 #else
 586 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)
 587 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)
 588 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)
 589 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)
 590 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)
 591 #endif
 592
 593 /*
 594  * State machine verbose
 595  */
 596 #if TCP_DEBUG_SM > 3
 597 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)                               \
 598 {                                                                       \
 599   ELOG_TYPE_DECLARE (_e) =                                              \
 600   {                                                                     \
 601     .format = "snd-wnd update: %u ",                                    \
 602     .format_args = "i4",                                                \
 603   };                                                                    \
 604   DECLARE_ETD(_tc, _e, 1);                                              \
 605   ed->data[0] = _tc->snd_wnd;                                           \
 606 }
 607
 608 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)                 \
 609 {                                                                       \
 610   ELOG_TYPE_DECLARE (_e) =                                              \
 611   {                                                                     \
 612     .format = "out: flags %x, bytes %u",                                \
 613     .format_args = "i4i4",                                              \
 614   };                                                                    \
 615   DECLARE_ETD(_tc, _e, 2);                                              \
 616   ed->data[0] = flags;                                                  \
 617   ed->data[1] = n_bytes;                                                \
 618 }
 619 #else
 620 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)
 621 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
 622 #endif
 623
 624 /*
 625  * Congestion Control
 626  */
 627
 628 #if TCP_DEBUG_CC
 629
 630 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)                      \
 631 {                                                                       \
 632   ELOG_TYPE_DECLARE (_e) =                                              \
 633   {                                                                     \
 634     .format = "cc: %s snd_space %u snd_una %u out %u flight %u",        \
 635     .format_args = "t4i4i4i4i4",                                        \
 636     .n_enum_strings = 7,                                                \
 637     .enum_strings = {                                                   \
 638       "fast-rxt",                                                       \
 639       "rxt-timeout",                                                    \
 640       "first-rxt",                                                      \
 641       "recovered",                                                      \
 642       "congestion",                                                     \
 643       "undo",                                                           \
 644       "recovery",                                                       \
 645     },                                                                  \
 646   };                                                                    \
 647   DECLARE_ETD(_tc, _e, 5);                                              \
 648   ed->data[0] = _sub_evt;                                               \
 649   ed->data[1] = tcp_available_cc_snd_space (_tc);                       \
 650   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 651   ed->data[3] = tcp_bytes_out(_tc);                                     \
 652   ed->data[4] = tcp_flight_size (_tc);                                  \
 653 }
 654 #else
 655 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)
 656 #endif
 657
 658 #if TCP_DEBUG_CC > 1
 659 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)               \
 660 {                                                                       \
 661   ELOG_TYPE_DECLARE (_e) =                                              \
 662   {                                                                     \
 663     .format = "rxt: snd_nxt %u offset %u snd %u rxt %u",                \
 664     .format_args = "i4i4i4i4",                                          \
 665   };                                                                    \
 666   DECLARE_ETD(_tc, _e, 4);                                              \
 667   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 668   ed->data[1] = offset;                                                 \
 669   ed->data[2] = n_bytes;                                                \
 670   ed->data[3] = _tc->snd_rxt_bytes;                                     \
 671 }
 672
 673 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, _btcp, ...)                    \
 674 {                                                                       \
 675   ELOG_TYPE_DECLARE (_e) =                                              \
 676   {                                                                     \
 677     .format = "dack-tx: rcv_nxt %u seq %u rcv_wnd %u snd_nxt %u av_wnd %u",\
 678     .format_args = "i4i4i4i4i4",                                        \
 679   };                                                                    \
 680   DECLARE_ETD(_tc, _e, 5);                                              \
 681   ed->data[0] = _tc->rcv_nxt - _tc->irs;                                \
 682   ed->data[1] = _btcp.seq_number - _tc->irs;                            \
 683   ed->data[2] = _tc->rcv_wnd;                                           \
 684   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 685   ed->data[4] = tcp_available_snd_wnd(_tc);                             \
 686 }
 687
 688 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)                           \
 689 {                                                                       \
 690   ELOG_TYPE_DECLARE (_e) =                                              \
 691   {                                                                     \
 692     .format = "dack-rx: snd_una %u cwnd %u snd_wnd %u flight %u rcv_wnd %u",\
 693     .format_args = "i4i4i4i4i4",                                        \
 694   };                                                                    \
 695   DECLARE_ETD(_tc, _e, 5);                                              \
 696   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 697   ed->data[1] = _tc->cwnd;                                              \
 698   ed->data[2] = _tc->snd_wnd;                                           \
 699   ed->data[3] = tcp_flight_size(_tc);                                   \
 700   ed->data[4] = _tc->rcv_wnd;                                           \
 701 }
 702
 703 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)                               \
 704 {                                                                       \
 705   ELOG_TYPE_DECLARE (_e) =                                              \
 706   {                                                                     \
 707     .format = "pack: snd_una %u snd_una_max %u",                        \
 708     .format_args = "i4i4",                                              \
 709   };                                                                    \
 710   DECLARE_ETD(_tc, _e, 2);                                              \
 711   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 712   ed->data[1] = _tc->snd_una_max - _tc->iss;                            \
 713 }
 714 #define TCP_EVT_CC_SCOREBOARD_HANDLER(_tc, ...)                         \
 715 {                                                                       \
 716 if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                 \
 717   {                                                                     \
 718     ELOG_TYPE_DECLARE (_e) =                                            \
 719     {                                                                   \
 720       .format = "sb1: holes %u lost %u sacked %u high %u highrxt %u",   \
 721       .format_args = "i4i4i4i4i4",                                      \
 722     };                                                                  \
 723     DECLARE_ETD(_tc, _e, 5);                                            \
 724     ed->data[0] = pool_elts(_tc->sack_sb.holes);                        \
 725     ed->data[1] = _tc->sack_sb.lost_bytes;                              \
 726     ed->data[2] = _tc->sack_sb.sacked_bytes;                            \
 727     ed->data[3] = _tc->sack_sb.high_sacked - _tc->iss;                  \
 728     ed->data[4] = _tc->sack_sb.high_rxt - _tc->iss;                     \
 729   }                                                                     \
 730 if (TCP_DEBUG_CC > 1 && _tc->sack_sb.last_sacked_bytes)                 \
 731   {                                                                     \
 732     sack_scoreboard_hole_t *hole;                                       \
 733     hole = scoreboard_first_hole (&_tc->sack_sb);                       \
 734     ELOG_TYPE_DECLARE (_e) =                                            \
 735     {                                                                   \
 736       .format = "sb2: first start: %u end %u last start %u end %u",     \
 737       .format_args = "i4i4i4i4",                                        \
 738     };                                                                  \
 739     DECLARE_ETD(_tc, _e, 4);                                            \
 740     ed->data[0] = hole ? hole->start - _tc->iss : 0;                    \
 741     ed->data[1] = hole ? hole->end - _tc->iss : 0;                      \
 742     hole = scoreboard_last_hole (&_tc->sack_sb);                        \
 743     ed->data[2] = hole ? hole->start - _tc->iss : 0;                    \
 744     ed->data[3] = hole ? hole->end - _tc->iss : 0;                      \
 745   }                                                                     \
 746 }
 747 #define TCP_EVT_CC_SACKS_HANDLER(_tc, ...)                              \
 748 {                                                                       \
 749 if (TCP_DEBUG_CC > 1)                                                   \
 750   {                                                                     \
 751     ELOG_TYPE_DECLARE (_e) =                                            \
 752     {                                                                   \
 753       .format = "sacks: blocks %u bytes %u",                            \
 754       .format_args = "i4i4",                                            \
 755     };                                                                  \
 756     DECLARE_ETD(_tc, _e, 2);                                            \
 757     ed->data[0] = vec_len (_tc->snd_sacks);                             \
 758     ed->data[1] = tcp_sack_list_bytes (_tc);                            \
 759   }                                                                     \
 760 }
 761 #define TCP_EVT_CC_INPUT_HANDLER(_tc, _len, _written, ...)              \
 762 {                                                                       \
 763   ELOG_TYPE_DECLARE (_e) =                                              \
 764   {                                                                     \
 765     .format = "cc input: len %u written %d rcv_nxt %u rcv_wnd(o) %d",   \
 766     .format_args = "i4i4i4i4",                                          \
 767   };                                                                    \
 768   DECLARE_ETD(_tc, _e, 4);                                              \
 769   ed->data[0] = _len;                                                   \
 770   ed->data[1] = _written;                                               \
 771   ed->data[2] = _tc->rcv_nxt - _tc->irs;                                \
 772   ed->data[3] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);           \
 773 }
 774 #else
 775 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
 776 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, _btcp, ...)
 777 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)
 778 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
 779 #define TCP_EVT_CC_SCOREBOARD_HANDLER(_tc, ...)
 780 #define TCP_EVT_CC_SACKS_HANDLER(_tc, ...)
 781 #define TCP_EVT_CC_INPUT_HANDLER(_tc, _len, _written, ...)
 782 #endif
 783
 784 /*
 785  * Congestion control stats
 786  */
 787 #if TCP_DEBUG_CC_STAT
 788
 789 #define STATS_INTERVAL 1
 790
 791 #define TCP_EVT_CC_RTO_STAT_HANDLER(_tc, ...)                           \
 792 {                                                                       \
 793 if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now())            \
 794 {                                                                       \
 795   ELOG_TYPE_DECLARE (_e) =                                              \
 796   {                                                                     \
 797     .format = "rcv_stat: rto %u srtt %u rttvar %u ",                    \
 798     .format_args = "i4i4i4",                                            \
 799   };                                                                    \
 800   DECLARE_ETD(_tc, _e, 3);                                              \
 801   ed->data[0] = _tc->rto;                                               \
 802   ed->data[1] = _tc->srtt;                                              \
 803   ed->data[2] = _tc->rttvar;                                            \
 804 }                                                                       \
 805 }
 806 #define TCP_EVT_CC_SND_STAT_HANDLER(_tc, ...)                           \
 807 {                                                                       \
 808 if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now())            \
 809 {                                                                       \
 810   ELOG_TYPE_DECLARE (_e) =                                              \
 811   {                                                                     \
 812     .format = "snd_stat: dack %u sacked %u lost %u out %u rxt %u",      \
 813     .format_args = "i4i4i4i4i4",                                        \
 814   };                                                                    \
 815   DECLARE_ETD(_tc, _e, 5);                                              \
 816   ed->data[0] = _tc->rcv_dupacks;                                       \
 817   ed->data[1] = _tc->sack_sb.sacked_bytes;                              \
 818   ed->data[2] = _tc->sack_sb.lost_bytes;                                \
 819   ed->data[3] = tcp_bytes_out (_tc);                                    \
 820   ed->data[3] = _tc->snd_rxt_bytes;                                     \
 821 }                                                                       \
 822 }
 823
 824 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...)                               \
 825 {                                                                       \
 826 if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now())            \
 827 {                                                                       \
 828   ELOG_TYPE_DECLARE (_e) =                                              \
 829   {                                                                     \
 830     .format = "cc_stat: cwnd %u flight %u space %u ssthresh %u snd_wnd %u",\
 831     .format_args = "i4i4i4i4i4",                                        \
 832   };                                                                    \
 833   DECLARE_ETD(_tc, _e, 5);                                              \
 834   ed->data[0] = _tc->cwnd;                                              \
 835   ed->data[1] = tcp_flight_size (_tc);                                  \
 836   ed->data[2] = tcp_snd_space (_tc);                                    \
 837   ed->data[3] = _tc->ssthresh;                                          \
 838   ed->data[4] = _tc->snd_wnd;                                           \
 839   TCP_EVT_CC_RTO_STAT_HANDLER (_tc);                                    \
 840   _tc->c_cc_stat_tstamp = tcp_time_now();                               \
 841 }                                                                       \
 842 }
 843 #else
 844 #define TCP_EVT_CC_STAT_HANDLER(_tc, ...)
 845 #endif
 846
 847 /*
 848  * Buffer allocation
 849  */
 850 #if TCP_DEBUG_BUFFER_ALLOCATION
 851
 852 #define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)                   \
 853 {                                                                       \
 854   static u32 *buffer_fail_counters;                                     \
 855   if (PREDICT_FALSE (buffer_fail_counters == 0))                        \
 856     {                                                                   \
 857       u32 num_threads;                                                  \
 858       vlib_thread_main_t *vtm = vlib_get_thread_main ();                \
 859       num_threads = 1 /* main thread */  + vtm->n_threads;              \
 860       vec_validate (buffer_fail_counters, num_threads - 1);             \
 861     }                                                                   \
 862   if (PREDICT_FALSE (tcp_main.buffer_fail_fraction != 0.0))             \
 863     {                                                                   \
 864       if (PREDICT_TRUE (buffer_fail_counters[thread_index] > 0))        \
 865         {                                                               \
 866           if ((1.0 / (f32) (buffer_fail_counters[thread_index]))        \
 867               < tcp_main.buffer_fail_fraction)                          \
 868             {                                                           \
 869               buffer_fail_counters[thread_index] = 0.0000001;           \
 870               return -1;                                                \
 871             }                                                           \
 872         }                                                               \
 873       buffer_fail_counters[thread_index] ++;                            \
 874     }                                                                   \
 875 }
 876 #else
 877 #define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)
 878 #endif
 879
 880 #endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
 881 /*
 882  * fd.io coding-style-patch-verification: ON
 883  *
 884  * Local Variables:
 885  * eval: (c-set-style "gnu")
 886  * End:
 887  */