FD.io VPP  v18.10-32-g1161dda
Vector Packet Processing
tcp_debug.h
Go to the documentation of this file.
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  */
tcp_dbg_e
enum _tcp_dbg tcp_dbg_e
foreach_tcp_dbg_evt
#define foreach_tcp_dbg_evt
Definition: tcp_debug.h:27
tcp_dbg_evt_e
enum _tcp_dbg_evt tcp_dbg_evt_e