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_CC (1)
  23 #define TCP_DEBUG_VERBOSE (0)
  24
  25 #define foreach_tcp_dbg_evt             \
  26   _(INIT, "")                           \
  27   _(DEALLOC, "")                        \
  28   _(OPEN, "open")                       \
  29   _(CLOSE, "close")                     \
  30   _(BIND, "bind")                       \
  31   _(UNBIND, "unbind")                   \
  32   _(DELETE, "delete")                   \
  33   _(SYN_SENT, "SYN sent")               \
  34   _(FIN_SENT, "FIN sent")               \
  35   _(ACK_SENT, "ACK sent")               \
  36   _(DUPACK_SENT, "DUPACK sent")         \
  37   _(RST_SENT, "RST sent")               \
  38   _(SYN_RCVD, "SYN rcvd")               \
  39   _(ACK_RCVD, "ACK rcvd")               \
  40   _(DUPACK_RCVD, "DUPACK rcvd")         \
  41   _(FIN_RCVD, "FIN rcvd")               \
  42   _(RST_RCVD, "RST rcvd")               \
  43   _(PKTIZE, "packetize")                \
  44   _(INPUT, "in")                        \
  45   _(SND_WND, "snd_wnd update")          \
  46   _(OUTPUT, "output")                   \
  47   _(TIMER_POP, "timer pop")             \
  48   _(CC_RTX, "retransmit")               \
  49   _(CC_EVT, "cc event")                 \
  50   _(CC_PACK, "cc partial ack")          \
  51   _(SEG_INVALID, "invalid segment")     \
  52   _(ACK_RCV_ERR, "invalid ack")         \
  53
  54 typedef enum _tcp_dbg
  55 {
  56 #define _(sym, str) TCP_DBG_##sym,
  57   foreach_tcp_dbg_evt
  58 #undef _
  59 } tcp_dbg_e;
  60
  61 typedef enum _tcp_dbg_evt
  62 {
  63 #define _(sym, str) TCP_EVT_##sym,
  64   foreach_tcp_dbg_evt
  65 #undef _
  66 } tcp_dbg_evt_e;
  67
  68 #if TCP_DEBUG
  69
  70 #define TRANSPORT_DEBUG (1)
  71
  72 #define TCP_DBG(_tc, _evt, _args...)                                    \
  73 {                                                                       \
  74     u8 *_tmp = 0;                                                       \
  75     _tmp = format(_tmp, "%U", format_tcp_connection_verbose, _tc);      \
  76     clib_warning("%s", _tmp);                                           \
  77     vec_free(_tmp);                                                     \
  78 }
  79
  80 #define DECLARE_ETD(_tc, _e, _size)                                     \
  81   struct                                                                \
  82   {                                                                     \
  83     u32 data[_size];                                                    \
  84   } * ed;                                                               \
  85   ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main,                    \
  86                         _e, _tc->c_elog_track)
  87
  88 #define TCP_EVT_INIT_HANDLER(_tc, _fmt, ...)                            \
  89 {                                                                       \
  90   _tc->c_elog_track.name =                                              \
  91         (char *) format (0, _fmt, _tc->c_c_index, 0);                   \
  92   elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
  93 }
  94
  95 #define TCP_EVT_DEALLOC_HANDLER(_tc, ...)                               \
  96 {                                                                       \
  97   vec_free (_tc->c_elog_track.name);                                    \
  98 }
  99
 100 #define TCP_EVT_OPEN_HANDLER(_tc, ...)                                  \
 101 {                                                                       \
 102   TCP_EVT_INIT_HANDLER(_tc, "s%d%c");                                   \
 103   ELOG_TYPE_DECLARE (_e) =                                              \
 104   {                                                                     \
 105     .format = "open: index %d",                                         \
 106     .format_args = "i4",                                                \
 107   };                                                                    \
 108   DECLARE_ETD(_tc, _e, 1);                                              \
 109   ed->data[0] = _tc->c_c_index;                                         \
 110 }
 111
 112 #define TCP_EVT_CLOSE_HANDLER(_tc, ...)                                 \
 113 {                                                                       \
 114   ELOG_TYPE_DECLARE (_e) =                                              \
 115   {                                                                     \
 116     .format = "close: %d",                                              \
 117     .format_args = "i4",                                                \
 118   };                                                                    \
 119   DECLARE_ETD(_tc, _e, 1);                                              \
 120   ed->data[0] = _tc->c_c_index;                                         \
 121 }
 122
 123 #define TCP_EVT_BIND_HANDLER(_tc, ...)                                  \
 124 {                                                                       \
 125   TCP_EVT_INIT_HANDLER(_tc, "l%d%c");                                   \
 126   ELOG_TYPE_DECLARE (_e) =                                              \
 127   {                                                                     \
 128     .format = "bind: listener %d",                                      \
 129   };                                                                    \
 130   DECLARE_ETD(_tc, _e, 1);                                              \
 131   ed->data[0] = _tc->c_c_index;                                         \
 132 }
 133
 134 #define TCP_EVT_UNBIND_HANDLER(_tc, ...)                                \
 135 {                                                                       \
 136   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 137   ELOG_TYPE_DECLARE (_e) =                                              \
 138   {                                                                     \
 139     .format = "unbind: listener %d",                                    \
 140   };                                                                    \
 141   DECLARE_ETD(_tc, _e, 1);                                              \
 142   ed->data[0] = _tc->c_c_index;                                         \
 143   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 144 }
 145
 146 #define TCP_EVT_DELETE_HANDLER(_tc, ...)                                \
 147 {                                                                       \
 148   ELOG_TYPE_DECLARE (_e) =                                              \
 149   {                                                                     \
 150     .format = "delete: %d",                                             \
 151     .format_args = "i4",                                                \
 152   };                                                                    \
 153   DECLARE_ETD(_tc, _e, 1);                                              \
 154   ed->data[0] = _tc->c_c_index;                                         \
 155   TCP_EVT_DEALLOC_HANDLER(_tc);                                         \
 156 }
 157
 158 #define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)                              \
 159 {                                                                       \
 160   ELOG_TYPE_DECLARE (_e) =                                              \
 161   {                                                                     \
 162     .format = "ack_prep: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u",    \
 163     .format_args = "i4i4i4i4",                                          \
 164   };                                                                    \
 165   DECLARE_ETD(_tc, _e, 4);                                              \
 166   ed->data[0] = _tc->rcv_nxt - _tc->rcv_las;                            \
 167   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 168   ed->data[2] = _tc->rcv_wnd;                                           \
 169   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 170 }
 171
 172 #define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...)                           \
 173 {                                                                       \
 174   ELOG_TYPE_DECLARE (_e) =                                              \
 175   {                                                                     \
 176     .format = "dack_tx: rcv_nxt %u rcv_wnd %u snd_nxt %u av-wnd %u",    \
 177     .format_args = "i4i4i4i4",                                          \
 178   };                                                                    \
 179   DECLARE_ETD(_tc, _e, 4);                                              \
 180   ed->data[0] = _tc->rcv_nxt - _tc->irs;                                \
 181   ed->data[1] = _tc->rcv_wnd;                                           \
 182   ed->data[2] = _tc->snd_nxt - _tc->iss;                                \
 183   ed->data[3] = tcp_available_wnd(_tc);                                 \
 184 }
 185
 186 #define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)                              \
 187 {                                                                       \
 188   ELOG_TYPE_DECLARE (_e) =                                              \
 189   {                                                                     \
 190     .format = "SYNtx: iss %u",                                  \
 191     .format_args = "i4",                                                \
 192   };                                                                    \
 193   DECLARE_ETD(_tc, _e, 1);                                              \
 194   ed->data[0] = _tc->iss;                                               \
 195 }
 196
 197 #define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)                              \
 198 {                                                                       \
 199   ELOG_TYPE_DECLARE (_e) =                                              \
 200   {                                                                     \
 201     .format = "FINtx: snd_nxt %d rcv_nxt %d",                           \
 202     .format_args = "i4i4",                                              \
 203   };                                                                    \
 204   DECLARE_ETD(_tc, _e, 2);                                              \
 205   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 206   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 207 }
 208
 209 #define TCP_EVT_RST_SENT_HANDLER(_tc, ...)                              \
 210 {                                                                       \
 211   ELOG_TYPE_DECLARE (_e) =                                              \
 212   {                                                                     \
 213     .format = "RSTtx: snd_nxt %d rcv_nxt %d",                           \
 214     .format_args = "i4i4",                                              \
 215   };                                                                    \
 216   DECLARE_ETD(_tc, _e, 2);                                              \
 217   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 218   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 219 }
 220
 221 #define TCP_EVT_SYN_RCVD_HANDLER(_tc, ...)                              \
 222 {                                                                       \
 223   TCP_EVT_INIT_HANDLER(_tc, "s%d%c");                                   \
 224   ELOG_TYPE_DECLARE (_e) =                                              \
 225   {                                                                     \
 226     .format = "SYNrx: irs %u",                                          \
 227     .format_args = "i4",                                                \
 228   };                                                                    \
 229   DECLARE_ETD(_tc, _e, 1);                                              \
 230   ed->data[0] = _tc->irs;                                               \
 231 }
 232
 233 #define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)                              \
 234 {                                                                       \
 235   ELOG_TYPE_DECLARE (_e) =                                              \
 236   {                                                                     \
 237     .format = "FINrx: snd_nxt %d rcv_nxt %d",                           \
 238     .format_args = "i4i4",                                              \
 239   };                                                                    \
 240   DECLARE_ETD(_tc, _e, 2);                                              \
 241   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 242   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 243 }
 244
 245 #define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)                              \
 246 {                                                                       \
 247   ELOG_TYPE_DECLARE (_e) =                                              \
 248   {                                                                     \
 249     .format = "RSTrx: snd_nxt %d rcv_nxt %d",                           \
 250     .format_args = "i4i4",                                              \
 251   };                                                                    \
 252   DECLARE_ETD(_tc, _e, 2);                                              \
 253   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 254   ed->data[1] = _tc->rcv_nxt - _tc->irs;                                \
 255 }
 256
 257 #define TCP_EVT_ACK_RCVD_HANDLER(_tc, _ack, ...)                        \
 258 {                                                                       \
 259   ELOG_TYPE_DECLARE (_e) =                                              \
 260   {                                                                     \
 261     .format = "acked: %u snd_una %u ack %u cwnd %u inflight %u",        \
 262     .format_args = "i4i4i4i4i4",                                        \
 263   };                                                                    \
 264   DECLARE_ETD(_tc, _e, 5);                                              \
 265   ed->data[0] = _tc->bytes_acked;                                       \
 266   ed->data[1] = _tc->snd_una - _tc->iss;                                \
 267   ed->data[2] = _ack - _tc->iss;                                        \
 268   ed->data[3] = _tc->cwnd;                                              \
 269   ed->data[4] = tcp_flight_size(_tc);                                   \
 270 }
 271
 272 #define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)                           \
 273 {                                                                       \
 274   ELOG_TYPE_DECLARE (_e) =                                              \
 275   {                                                                     \
 276     .format = "dack_rx: snd_una %u cwnd %u snd_wnd %u inflight %u",     \
 277     .format_args = "i4i4i4i4",                                          \
 278   };                                                                    \
 279   DECLARE_ETD(_tc, _e, 4);                                              \
 280   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 281   ed->data[1] = _tc->cwnd;                                              \
 282   ed->data[2] = _tc->snd_wnd;                                           \
 283   ed->data[3] = tcp_flight_size(_tc);                                   \
 284 }
 285
 286 #define TCP_EVT_PKTIZE_HANDLER(_tc, ...)                                \
 287 {                                                                       \
 288   ELOG_TYPE_DECLARE (_e) =                                              \
 289   {                                                                     \
 290     .format = "pktize: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
 291     .format_args = "i4i4i4i4i4",                                        \
 292   };                                                                    \
 293   DECLARE_ETD(_tc, _e, 5);                                              \
 294   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 295   ed->data[1] = _tc->snd_nxt - _tc->iss;                                \
 296   ed->data[2] = tcp_available_snd_space (_tc);                          \
 297   ed->data[3] = tcp_flight_size (_tc);                                  \
 298   ed->data[4] = _tc->rcv_wnd;                                           \
 299 }
 300
 301 #define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)          \
 302 {                                                                       \
 303   ELOG_TYPE_DECLARE (_e) =                                              \
 304   {                                                                     \
 305     .format = "in: %s len %u written %d rcv_nxt %u free wnd %d",        \
 306     .format_args = "t4i4i4i4i4",                                        \
 307     .n_enum_strings = 2,                                                \
 308     .enum_strings = {                                                   \
 309       "order",                                                          \
 310       "ooo",                                                            \
 311     },                                                                  \
 312   };                                                                    \
 313   DECLARE_ETD(_tc, _e, 5);                                              \
 314   ed->data[0] = _type;                                                  \
 315   ed->data[1] = _len;                                                   \
 316   ed->data[2] = _written;                                               \
 317   ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written;                   \
 318   ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las);           \
 319 }
 320
 321 #define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)            \
 322 {                                                                       \
 323   tcp_connection_t *_tc;                                                \
 324   if (_timer_id == TCP_TIMER_RETRANSMIT_SYN)                            \
 325     {                                                                   \
 326       _tc = tcp_half_open_connection_get (_tc_index);                   \
 327     }                                                                   \
 328   else                                                                  \
 329     {                                                                   \
 330       u32 _thread_index = os_get_cpu_number ();                         \
 331       _tc = tcp_connection_get (_tc_index, _thread_index);              \
 332     }                                                                   \
 333   ELOG_TYPE_DECLARE (_e) =                                              \
 334   {                                                                     \
 335     .format = "TimerPop: %s (%d)",                                      \
 336     .format_args = "t4i4",                                              \
 337     .n_enum_strings = 7,                                                \
 338     .enum_strings = {                                                   \
 339       "retransmit",                                                     \
 340       "delack",                                                         \
 341       "BUG",                                                            \
 342       "keep",                                                           \
 343       "waitclose",                                                      \
 344       "retransmit syn",                                                 \
 345       "establish",                                                      \
 346     },                                                                  \
 347   };                                                                    \
 348   DECLARE_ETD(_tc, _e, 2);                                              \
 349   ed->data[0] = _timer_id;                                              \
 350   ed->data[1] = _timer_id;                                              \
 351 }
 352
 353 #define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...)               \
 354 {                                                                       \
 355   ELOG_TYPE_DECLARE (_e) =                                              \
 356   {                                                                     \
 357     .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u wnd %u",    \
 358     .format_args = "i4i4i4i4i4",                                        \
 359   };                                                                    \
 360   DECLARE_ETD(_tc, _e, 5);                                              \
 361   ed->data[0] = _seq - _tc->irs;                                        \
 362   ed->data[1] = _end - _tc->irs;                                        \
 363   ed->data[2] = _tc->rcv_las - _tc->irs;                                \
 364   ed->data[3] = _tc->rcv_nxt - _tc->irs;                                \
 365   ed->data[4] = _tc->rcv_wnd;                                           \
 366 }
 367
 368 #define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)              \
 369 {                                                                       \
 370   ELOG_TYPE_DECLARE (_e) =                                              \
 371   {                                                                     \
 372     .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u",    \
 373     .format_args = "t4i4i4i4i4",                                        \
 374     .n_enum_strings = 3,                                                \
 375     .enum_strings = {                                                   \
 376       "invalid",                                                        \
 377       "old",                                                            \
 378       "future",                                                         \
 379     },                                                                  \
 380   };                                                                    \
 381   DECLARE_ETD(_tc, _e, 5);                                              \
 382   ed->data[0] = _type;                                                  \
 383   ed->data[1] = _ack - _tc->iss;                                        \
 384   ed->data[2] = _tc->snd_una - _tc->iss;                                \
 385   ed->data[3] = _tc->snd_nxt - _tc->iss;                                \
 386   ed->data[4] = _tc->snd_una_max - _tc->iss;                            \
 387 }
 388
 389 /*
 390  * Congestion Control
 391  */
 392
 393 #if TCP_DEBUG_CC
 394 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)               \
 395 {                                                                       \
 396   ELOG_TYPE_DECLARE (_e) =                                              \
 397   {                                                                     \
 398     .format = "rtx: snd_nxt %u offset %u snd %u rtx %u",                \
 399     .format_args = "i4i4i4i4",                                          \
 400   };                                                                    \
 401   DECLARE_ETD(_tc, _e, 4);                                              \
 402   ed->data[0] = _tc->snd_nxt - _tc->iss;                                \
 403   ed->data[1] = offset;                                                 \
 404   ed->data[2] = n_bytes;                                                \
 405   ed->data[3] = _tc->rtx_bytes;                                         \
 406 }
 407
 408 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)                      \
 409 {                                                                       \
 410   ELOG_TYPE_DECLARE (_e) =                                              \
 411   {                                                                     \
 412     .format = "cc: %s wnd %u snd_cong %u rtx_bytes %u",                 \
 413     .format_args = "t4i4i4i4",                                          \
 414     .n_enum_strings = 5,                                                \
 415     .enum_strings = {                                                   \
 416       "fast-rtx",                                                       \
 417       "rtx-timeout",                                                    \
 418       "first-rtx",                                                      \
 419       "recovered",                                                      \
 420       "congestion",                                                     \
 421     },                                                                  \
 422   };                                                                    \
 423   DECLARE_ETD(_tc, _e, 4);                                              \
 424   ed->data[0] = _sub_evt;                                               \
 425   ed->data[1] = tcp_available_snd_space (_tc);                          \
 426   ed->data[2] = _tc->snd_congestion - _tc->iss;                         \
 427   ed->data[3] = _tc->rtx_bytes;                                         \
 428 }
 429
 430 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)                               \
 431 {                                                                       \
 432   ELOG_TYPE_DECLARE (_e) =                                              \
 433   {                                                                     \
 434     .format = "pack: snd_una %u snd_una_max %u",                        \
 435     .format_args = "i4i4",                                              \
 436   };                                                                    \
 437   DECLARE_ETD(_tc, _e, 2);                                              \
 438   ed->data[0] = _tc->snd_una - _tc->iss;                                \
 439   ed->data[1] = _tc->snd_una_max - _tc->iss;                            \
 440 }
 441
 442 #else
 443 #define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
 444 #define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, _snd_space, ...)
 445 #define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
 446 #endif
 447
 448 #if TCP_DBG_VERBOSE
 449 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)                               \
 450 {                                                                       \
 451   ELOG_TYPE_DECLARE (_e) =                                              \
 452   {                                                                     \
 453     .format = "snd_wnd update: %u ",                                    \
 454     .format_args = "i4",                                                \
 455   };                                                                    \
 456   DECLARE_ETD(_tc, _e, 1);                                              \
 457   ed->data[0] = _tc->snd_wnd;                                           \
 458 }
 459
 460 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)                 \
 461 {                                                                       \
 462   ELOG_TYPE_DECLARE (_e) =                                              \
 463   {                                                                     \
 464     .format = "out: flags %x, bytes %u",                                \
 465     .format_args = "i4i4",                                              \
 466   };                                                                    \
 467   DECLARE_ETD(_tc, _e, 2);                                              \
 468   ed->data[0] = flags;                                                  \
 469   ed->data[1] = n_bytes;                                                \
 470 }
 471 #else
 472 #define TCP_EVT_SND_WND_HANDLER(_tc, ...)
 473 #define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
 474 #endif
 475
 476 #define CONCAT_HELPER(_a, _b) _a##_b
 477 #define CC(_a, _b) CONCAT_HELPER(_a, _b)
 478 #define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
 479
 480 #else
 481 #define TCP_EVT_DBG(_evt, _args...)
 482 #endif
 483
 484
 485 #endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
 486 /*
 487  * fd.io coding-style-patch-verification: ON
 488  *
 489  * Local Variables:
 490  * eval: (c-set-style "gnu")
 491  * End:
 492  */