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