blob: d35691173c15f09c398160e900aabefca70c7ba1 [file] [log] [blame]
Florin Corase69f4952017-03-07 10:06:24 -08001/*
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)
Florin Coras2f8d8fa2018-01-26 06:36:04 -080022#define TCP_DEBUG_SM (0)
Florin Corasf1762d62017-09-24 19:43:08 -040023#define TCP_DEBUG_CC (0)
Florin Coras68810622017-07-24 17:40:28 -070024#define TCP_DEBUG_CC_STAT (1)
Florin Corasf988e692017-11-27 04:34:14 -050025#define TCP_DEBUG_BUFFER_ALLOCATION (0)
Florin Corase69f4952017-03-07 10:06:24 -080026
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") \
Florin Coras6534b7a2017-07-18 05:38:03 -040036 _(SYNACK_SENT, "SYNACK sent") \
37 _(SYNACK_RCVD, "SYNACK rcvd") \
38 _(SYN_RXT, "SYN retransmit") \
Florin Corase69f4952017-03-07 10:06:24 -080039 _(FIN_SENT, "FIN sent") \
Florin Coras6792ec02017-03-13 03:49:51 -070040 _(ACK_SENT, "ACK sent") \
41 _(DUPACK_SENT, "DUPACK sent") \
Florin Corase69f4952017-03-07 10:06:24 -080042 _(RST_SENT, "RST sent") \
43 _(SYN_RCVD, "SYN rcvd") \
44 _(ACK_RCVD, "ACK rcvd") \
Florin Coras6792ec02017-03-13 03:49:51 -070045 _(DUPACK_RCVD, "DUPACK rcvd") \
Florin Corase69f4952017-03-07 10:06:24 -080046 _(FIN_RCVD, "FIN rcvd") \
47 _(RST_RCVD, "RST rcvd") \
Florin Coras6534b7a2017-07-18 05:38:03 -040048 _(STATE_CHANGE, "state change") \
Florin Corase69f4952017-03-07 10:06:24 -080049 _(PKTIZE, "packetize") \
50 _(INPUT, "in") \
Florin Coras6792ec02017-03-13 03:49:51 -070051 _(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") \
Florin Corasf03a59a2017-06-09 21:07:32 -070057 _(CC_STAT, "cc stats") \
58 _(CC_RTO_STAT, "cc rto stats") \
Florin Coras6792ec02017-03-13 03:49:51 -070059 _(SEG_INVALID, "invalid segment") \
Florin Corasc28764f2017-04-26 00:08:42 -070060 _(PAWS_FAIL, "failed paws check") \
Florin Coras6792ec02017-03-13 03:49:51 -070061 _(ACK_RCV_ERR, "invalid ack") \
Florin Coras3e350af2017-03-30 02:54:28 -070062 _(RCV_WND_SHRUNK, "shrunk rcv_wnd") \
Florin Corase69f4952017-03-07 10:06:24 -080063
64typedef enum _tcp_dbg
65{
66#define _(sym, str) TCP_DBG_##sym,
67 foreach_tcp_dbg_evt
68#undef _
69} tcp_dbg_e;
70
71typedef enum _tcp_dbg_evt
72{
73#define _(sym, str) TCP_EVT_##sym,
74 foreach_tcp_dbg_evt
75#undef _
76} tcp_dbg_evt_e;
77
78#if TCP_DEBUG
79
80#define TRANSPORT_DEBUG (1)
81
Florin Corasf03a59a2017-06-09 21:07:32 -070082/*
83 * Infra and evt track setup
84 */
85
Florin Coras9d063042017-09-14 03:08:00 -040086#define TCP_DBG(_fmt, _args...) clib_warning (_fmt, ##_args)
Florin Corase69f4952017-03-07 10:06:24 -080087
88#define DECLARE_ETD(_tc, _e, _size) \
89 struct \
90 { \
91 u32 data[_size]; \
92 } * ed; \
93 ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, \
94 _e, _tc->c_elog_track)
95
Florin Coras6534b7a2017-07-18 05:38:03 -040096#define TCP_DBG_IP_TAG_LCL(_tc) \
Florin Corase69f4952017-03-07 10:06:24 -080097{ \
Florin Coras6534b7a2017-07-18 05:38:03 -040098 if (_tc->c_is_ip4) \
99 { \
100 ELOG_TYPE_DECLARE (_e) = \
101 { \
102 .format = "lcl: %d.%d.%d.%d:%d", \
103 .format_args = "i4i4i4i4i4", \
104 }; \
105 DECLARE_ETD(_tc, _e, 5); \
106 ed->data[0] = _tc->c_lcl_ip.ip4.as_u8[0]; \
107 ed->data[1] = _tc->c_lcl_ip.ip4.as_u8[1]; \
108 ed->data[2] = _tc->c_lcl_ip.ip4.as_u8[2]; \
109 ed->data[3] = _tc->c_lcl_ip.ip4.as_u8[3]; \
110 ed->data[4] = clib_net_to_host_u16(_tc->c_lcl_port); \
111 } \
112}
113
114#define TCP_DBG_IP_TAG_RMT(_tc) \
115{ \
116 if (_tc->c_is_ip4) \
117 { \
118 ELOG_TYPE_DECLARE (_e) = \
119 { \
120 .format = "rmt: %d.%d.%d.%d:%d", \
121 .format_args = "i4i4i4i4i4", \
122 }; \
123 DECLARE_ETD(_tc, _e, 5); \
124 ed->data[0] = _tc->c_rmt_ip.ip4.as_u8[0]; \
125 ed->data[1] = _tc->c_rmt_ip.ip4.as_u8[1]; \
126 ed->data[2] = _tc->c_rmt_ip.ip4.as_u8[2]; \
127 ed->data[3] = _tc->c_rmt_ip.ip4.as_u8[3]; \
128 ed->data[4] = clib_net_to_host_u16(_tc->c_rmt_port); \
129 } \
130}
131
132#define TCP_EVT_INIT_HANDLER(_tc, _is_l, ...) \
133{ \
134 char *_fmt = _is_l ? "l[%d].%d:%d%c" : "[%d].%d:%d->.%d:%d%c"; \
135 if (_tc->c_is_ip4) \
136 { \
137 _tc->c_elog_track.name = \
138 (char *) format (0, _fmt, _tc->c_thread_index, \
139 _tc->c_lcl_ip.ip4.as_u8[3], \
140 clib_net_to_host_u16(_tc->c_lcl_port), \
141 _tc->c_rmt_ip.ip4.as_u8[3], \
142 clib_net_to_host_u16(_tc->c_rmt_port), 0); \
143 } \
144 else \
145 _tc->c_elog_track.name = \
146 (char *) format (0, _fmt, _tc->c_thread_index, \
147 _tc->c_lcl_ip.ip6.as_u8[15], \
148 clib_net_to_host_u16(_tc->c_lcl_port), \
149 _tc->c_rmt_ip.ip6.as_u8[15], \
150 clib_net_to_host_u16(_tc->c_rmt_port), 0); \
Florin Corase69f4952017-03-07 10:06:24 -0800151 elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
Florin Coras6534b7a2017-07-18 05:38:03 -0400152 TCP_DBG_IP_TAG_LCL(_tc); \
153 TCP_DBG_IP_TAG_RMT(_tc); \
Florin Corase69f4952017-03-07 10:06:24 -0800154}
155
156#define TCP_EVT_DEALLOC_HANDLER(_tc, ...) \
157{ \
158 vec_free (_tc->c_elog_track.name); \
159}
160
161#define TCP_EVT_OPEN_HANDLER(_tc, ...) \
162{ \
Florin Coras6534b7a2017-07-18 05:38:03 -0400163 TCP_EVT_INIT_HANDLER(_tc, 0); \
Florin Corase69f4952017-03-07 10:06:24 -0800164 ELOG_TYPE_DECLARE (_e) = \
165 { \
166 .format = "open: index %d", \
167 .format_args = "i4", \
168 }; \
169 DECLARE_ETD(_tc, _e, 1); \
170 ed->data[0] = _tc->c_c_index; \
171}
172
173#define TCP_EVT_CLOSE_HANDLER(_tc, ...) \
174{ \
175 ELOG_TYPE_DECLARE (_e) = \
176 { \
177 .format = "close: %d", \
178 .format_args = "i4", \
179 }; \
180 DECLARE_ETD(_tc, _e, 1); \
181 ed->data[0] = _tc->c_c_index; \
182}
183
184#define TCP_EVT_BIND_HANDLER(_tc, ...) \
185{ \
Florin Coras6534b7a2017-07-18 05:38:03 -0400186 TCP_EVT_INIT_HANDLER(_tc, 1); \
Florin Corase69f4952017-03-07 10:06:24 -0800187 ELOG_TYPE_DECLARE (_e) = \
188 { \
189 .format = "bind: listener %d", \
190 }; \
191 DECLARE_ETD(_tc, _e, 1); \
192 ed->data[0] = _tc->c_c_index; \
193}
194
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400195#define TCP_EVT_SYN_RCVD_HANDLER(_tc,_init, ...) \
Florin Coras68810622017-07-24 17:40:28 -0700196{ \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400197 if (_init) \
198 TCP_EVT_INIT_HANDLER(_tc, 0); \
Florin Coras68810622017-07-24 17:40:28 -0700199 ELOG_TYPE_DECLARE (_e) = \
200 { \
201 .format = "syn-rx: irs %u", \
202 .format_args = "i4", \
203 }; \
204 DECLARE_ETD(_tc, _e, 1); \
205 ed->data[0] = _tc->irs; \
206 TCP_EVT_STATE_CHANGE_HANDLER(_tc); \
207}
208
Florin Corase69f4952017-03-07 10:06:24 -0800209#define TCP_EVT_UNBIND_HANDLER(_tc, ...) \
210{ \
211 TCP_EVT_DEALLOC_HANDLER(_tc); \
212 ELOG_TYPE_DECLARE (_e) = \
213 { \
214 .format = "unbind: listener %d", \
215 }; \
216 DECLARE_ETD(_tc, _e, 1); \
217 ed->data[0] = _tc->c_c_index; \
218 TCP_EVT_DEALLOC_HANDLER(_tc); \
219}
220
221#define TCP_EVT_DELETE_HANDLER(_tc, ...) \
222{ \
223 ELOG_TYPE_DECLARE (_e) = \
224 { \
225 .format = "delete: %d", \
226 .format_args = "i4", \
227 }; \
Florin Coras6792ec02017-03-13 03:49:51 -0700228 DECLARE_ETD(_tc, _e, 1); \
Florin Corase69f4952017-03-07 10:06:24 -0800229 ed->data[0] = _tc->c_c_index; \
230 TCP_EVT_DEALLOC_HANDLER(_tc); \
231}
232
Florin Corasf03a59a2017-06-09 21:07:32 -0700233#define CONCAT_HELPER(_a, _b) _a##_b
234#define CC(_a, _b) CONCAT_HELPER(_a, _b)
235#define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
236#else
237#define TCP_EVT_DBG(_evt, _args...)
Florin Coras9d063042017-09-14 03:08:00 -0400238#define TCP_DBG(_fmt, _args...)
Florin Corasf03a59a2017-06-09 21:07:32 -0700239#endif
240
241/*
242 * State machine
243 */
244#if TCP_DEBUG_SM
245
Florin Coras6534b7a2017-07-18 05:38:03 -0400246#define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...) \
247{ \
248 ELOG_TYPE_DECLARE (_e) = \
249 { \
250 .format = "state: %s", \
251 .format_args = "t4", \
252 .n_enum_strings = 11, \
253 .enum_strings = { \
254 "closed", \
255 "listen", \
256 "syn-sent", \
257 "syn-rcvd", \
258 "established", \
259 "close_wait", \
260 "fin-wait-1", \
261 "last-ack", \
262 "closing", \
263 "fin-wait-2", \
264 "time-wait", \
265 }, \
266 }; \
267 DECLARE_ETD(_tc, _e, 1); \
268 ed->data[0] = _tc->state; \
269}
270
Florin Coras6534b7a2017-07-18 05:38:03 -0400271#define TCP_EVT_SYN_SENT_HANDLER(_tc, ...) \
272{ \
273 ELOG_TYPE_DECLARE (_e) = \
274 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400275 .format = "syn-tx: iss %u snd_una %u snd_una_max %u snd_nxt %u", \
276 .format_args = "i4i4i4i4", \
Florin Coras6534b7a2017-07-18 05:38:03 -0400277 }; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400278 DECLARE_ETD(_tc, _e, 4); \
Florin Coras6534b7a2017-07-18 05:38:03 -0400279 ed->data[0] = _tc->iss; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400280 ed->data[1] = _tc->snd_una - _tc->iss; \
281 ed->data[2] = _tc->snd_una_max - _tc->iss; \
282 ed->data[3] = _tc->snd_nxt - _tc->iss; \
Florin Coras6534b7a2017-07-18 05:38:03 -0400283 TCP_EVT_STATE_CHANGE_HANDLER(_tc); \
284}
285
286#define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...) \
287{ \
288 ELOG_TYPE_DECLARE (_e) = \
289 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400290 .format = "synack-tx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
291 .format_args = "i4i4i4i4i4", \
Florin Coras6534b7a2017-07-18 05:38:03 -0400292 }; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400293 DECLARE_ETD(_tc, _e, 5); \
Florin Coras6534b7a2017-07-18 05:38:03 -0400294 ed->data[0] = _tc->iss; \
295 ed->data[1] = _tc->irs; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400296 ed->data[2] = _tc->snd_una - _tc->iss; \
297 ed->data[3] = _tc->snd_nxt - _tc->iss; \
298 ed->data[4] = _tc->rcv_nxt - _tc->irs; \
Florin Coras6534b7a2017-07-18 05:38:03 -0400299}
300
301#define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...) \
302{ \
303 ELOG_TYPE_DECLARE (_e) = \
304 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400305 .format = "synack-rx: iss %u irs %u snd_una %u snd_nxt %u rcv_nxt %u",\
306 .format_args = "i4i4i4i4i4", \
Florin Coras6534b7a2017-07-18 05:38:03 -0400307 }; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400308 DECLARE_ETD(_tc, _e, 5); \
Florin Coras6534b7a2017-07-18 05:38:03 -0400309 ed->data[0] = _tc->iss; \
310 ed->data[1] = _tc->irs; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400311 ed->data[2] = _tc->snd_una - _tc->iss; \
312 ed->data[3] = _tc->snd_nxt - _tc->iss; \
313 ed->data[4] = _tc->rcv_nxt - _tc->irs; \
Florin Coras6534b7a2017-07-18 05:38:03 -0400314 TCP_EVT_STATE_CHANGE_HANDLER(_tc); \
315}
316
317#define TCP_EVT_FIN_SENT_HANDLER(_tc, ...) \
318{ \
319 ELOG_TYPE_DECLARE (_e) = \
320 { \
321 .format = "fin-tx: snd_nxt %d rcv_nxt %d", \
322 .format_args = "i4i4", \
323 }; \
324 DECLARE_ETD(_tc, _e, 2); \
325 ed->data[0] = _tc->snd_nxt - _tc->iss; \
326 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
327}
328
329#define TCP_EVT_RST_SENT_HANDLER(_tc, ...) \
330{ \
Florin Corasfc804d92018-01-26 01:27:01 -0800331if (_tc) \
Florin Coras6534b7a2017-07-18 05:38:03 -0400332 { \
Florin Corasfc804d92018-01-26 01:27:01 -0800333 ELOG_TYPE_DECLARE (_e) = \
334 { \
335 .format = "rst-tx: snd_nxt %d rcv_nxt %d", \
336 .format_args = "i4i4", \
337 }; \
338 DECLARE_ETD(_tc, _e, 2); \
339 ed->data[0] = _tc->snd_nxt - _tc->iss; \
340 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
341 TCP_EVT_STATE_CHANGE_HANDLER(_tc); \
342 } \
Florin Coras6534b7a2017-07-18 05:38:03 -0400343}
344
345#define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...) \
346{ \
347 ELOG_TYPE_DECLARE (_e) = \
348 { \
349 .format = "fin-rx: snd_nxt %d rcv_nxt %d", \
350 .format_args = "i4i4", \
351 }; \
352 DECLARE_ETD(_tc, _e, 2); \
353 ed->data[0] = _tc->snd_nxt - _tc->iss; \
354 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
355}
356
357#define TCP_EVT_RST_RCVD_HANDLER(_tc, ...) \
358{ \
359 ELOG_TYPE_DECLARE (_e) = \
360 { \
361 .format = "rst-rx: snd_nxt %d rcv_nxt %d", \
362 .format_args = "i4i4", \
363 }; \
364 DECLARE_ETD(_tc, _e, 2); \
365 ed->data[0] = _tc->snd_nxt - _tc->iss; \
366 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
367}
368
369#define TCP_EVT_SYN_RXT_HANDLER(_tc, _type, ...) \
370{ \
371 ELOG_TYPE_DECLARE (_e) = \
372 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400373 .format = "%s-rxt: iss %u irs %u snd_nxt %u rcv_nxt %u", \
374 .format_args = "t4i4i4i4i4", \
Florin Coras6534b7a2017-07-18 05:38:03 -0400375 .n_enum_strings = 2, \
376 .enum_strings = { \
377 "syn", \
378 "syn-ack", \
379 }, \
380 }; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400381 DECLARE_ETD(_tc, _e, 5); \
Florin Coras6534b7a2017-07-18 05:38:03 -0400382 ed->data[0] = _type; \
383 ed->data[1] = _tc->iss; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400384 ed->data[2] = _tc->irs; \
385 ed->data[3] = _tc->snd_nxt - _tc->iss; \
386 ed->data[4] = _tc->rcv_nxt - _tc->irs; \
Florin Coras6534b7a2017-07-18 05:38:03 -0400387}
388
389#else
390#define TCP_EVT_SYN_SENT_HANDLER(_tc, ...)
391#define TCP_EVT_SYNACK_SENT_HANDLER(_tc, ...)
392#define TCP_EVT_SYNACK_RCVD_HANDLER(_tc, ...)
393#define TCP_EVT_SYN_RXT_HANDLER(_tc, ...)
394#define TCP_EVT_FIN_SENT_HANDLER(_tc, ...)
395#define TCP_EVT_RST_SENT_HANDLER(_tc, ...)
396#define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...)
397#define TCP_EVT_RST_RCVD_HANDLER(_tc, ...)
398#define TCP_EVT_STATE_CHANGE_HANDLER(_tc, ...)
399#endif
400
401#if TCP_DEBUG_SM > 1
402
Florin Coras6792ec02017-03-13 03:49:51 -0700403#define TCP_EVT_ACK_SENT_HANDLER(_tc, ...) \
404{ \
405 ELOG_TYPE_DECLARE (_e) = \
406 { \
Florin Coras6534b7a2017-07-18 05:38:03 -0400407 .format = "ack-tx: acked %u rcv_nxt %u rcv_wnd %u snd_nxt %u snd_wnd %u",\
Florin Coras3e350af2017-03-30 02:54:28 -0700408 .format_args = "i4i4i4i4i4", \
Florin Coras6792ec02017-03-13 03:49:51 -0700409 }; \
Florin Coras3e350af2017-03-30 02:54:28 -0700410 DECLARE_ETD(_tc, _e, 5); \
Florin Coras6792ec02017-03-13 03:49:51 -0700411 ed->data[0] = _tc->rcv_nxt - _tc->rcv_las; \
412 ed->data[1] = _tc->rcv_nxt - _tc->irs; \
413 ed->data[2] = _tc->rcv_wnd; \
414 ed->data[3] = _tc->snd_nxt - _tc->iss; \
Florin Coras3e350af2017-03-30 02:54:28 -0700415 ed->data[4] = _tc->snd_wnd; \
Florin Coras6792ec02017-03-13 03:49:51 -0700416}
417
Florin Coras3e350af2017-03-30 02:54:28 -0700418#define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...) \
Florin Corase69f4952017-03-07 10:06:24 -0800419{ \
420 ELOG_TYPE_DECLARE (_e) = \
421 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400422 .format = "ack-rx: %u snd_una %u snd_wnd %u cwnd %u inflight %u", \
Florin Coras6792ec02017-03-13 03:49:51 -0700423 .format_args = "i4i4i4i4i4", \
Florin Corase69f4952017-03-07 10:06:24 -0800424 }; \
Florin Coras6792ec02017-03-13 03:49:51 -0700425 DECLARE_ETD(_tc, _e, 5); \
Florin Corase69f4952017-03-07 10:06:24 -0800426 ed->data[0] = _tc->bytes_acked; \
Florin Coras6792ec02017-03-13 03:49:51 -0700427 ed->data[1] = _tc->snd_una - _tc->iss; \
Florin Coras3e350af2017-03-30 02:54:28 -0700428 ed->data[2] = _tc->snd_wnd; \
Florin Coras6792ec02017-03-13 03:49:51 -0700429 ed->data[3] = _tc->cwnd; \
430 ed->data[4] = tcp_flight_size(_tc); \
431}
432
Florin Corase69f4952017-03-07 10:06:24 -0800433#define TCP_EVT_PKTIZE_HANDLER(_tc, ...) \
434{ \
435 ELOG_TYPE_DECLARE (_e) = \
436 { \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400437 .format = "tx: una %u snd_nxt %u space %u flight %u rcv_wnd %u",\
Florin Coras6792ec02017-03-13 03:49:51 -0700438 .format_args = "i4i4i4i4i4", \
Florin Corase69f4952017-03-07 10:06:24 -0800439 }; \
Florin Coras6792ec02017-03-13 03:49:51 -0700440 DECLARE_ETD(_tc, _e, 5); \
Florin Corase69f4952017-03-07 10:06:24 -0800441 ed->data[0] = _tc->snd_una - _tc->iss; \
442 ed->data[1] = _tc->snd_nxt - _tc->iss; \
Florin Coras4eeeaaf2017-09-05 14:03:37 -0400443 ed->data[2] = tcp_available_output_snd_space (_tc); \
Florin Coras6792ec02017-03-13 03:49:51 -0700444 ed->data[3] = tcp_flight_size (_tc); \
445 ed->data[4] = _tc->rcv_wnd; \
Florin Corase69f4952017-03-07 10:06:24 -0800446}
447
Florin Coras6792ec02017-03-13 03:49:51 -0700448#define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...) \
Florin Corase69f4952017-03-07 10:06:24 -0800449{ \
450 ELOG_TYPE_DECLARE (_e) = \
451 { \
Florin Coras3e350af2017-03-30 02:54:28 -0700452 .format = "in: %s len %u written %d rcv_nxt %u rcv_wnd(o) %d", \
Florin Coras6792ec02017-03-13 03:49:51 -0700453 .format_args = "t4i4i4i4i4", \
454 .n_enum_strings = 2, \
455 .enum_strings = { \
456 "order", \
457 "ooo", \
458 }, \
Florin Corase69f4952017-03-07 10:06:24 -0800459 }; \
Florin Coras6792ec02017-03-13 03:49:51 -0700460 DECLARE_ETD(_tc, _e, 5); \
461 ed->data[0] = _type; \
462 ed->data[1] = _len; \
463 ed->data[2] = _written; \
464 ed->data[3] = (_tc->rcv_nxt - _tc->irs) + _written; \
465 ed->data[4] = _tc->rcv_wnd - (_tc->rcv_nxt - _tc->rcv_las); \
Florin Corase69f4952017-03-07 10:06:24 -0800466}
467
468#define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...) \
469{ \
470 tcp_connection_t *_tc; \
flyingeagle23e8146b02017-04-26 20:06:52 +0800471 if (_timer_id == TCP_TIMER_RETRANSMIT_SYN \
472 || _timer_id == TCP_TIMER_ESTABLISH) \
Florin Corase69f4952017-03-07 10:06:24 -0800473 { \
474 _tc = tcp_half_open_connection_get (_tc_index); \
475 } \
476 else \
477 { \
Damjan Marion586afd72017-04-05 19:18:20 +0200478 u32 _thread_index = vlib_get_thread_index (); \
Florin Corase69f4952017-03-07 10:06:24 -0800479 _tc = tcp_connection_get (_tc_index, _thread_index); \
480 } \
481 ELOG_TYPE_DECLARE (_e) = \
482 { \
Florin Coras6534b7a2017-07-18 05:38:03 -0400483 .format = "timer-pop: %s (%d)", \
Florin Corase69f4952017-03-07 10:06:24 -0800484 .format_args = "t4i4", \
485 .n_enum_strings = 7, \
486 .enum_strings = { \
487 "retransmit", \
488 "delack", \
Florin Coras3e350af2017-03-30 02:54:28 -0700489 "persist", \
Florin Corase69f4952017-03-07 10:06:24 -0800490 "keep", \
491 "waitclose", \
492 "retransmit syn", \
493 "establish", \
494 }, \
495 }; \
Dave Barach2c25a622017-06-26 11:35:07 -0400496 if (_tc) \
497 { \
498 DECLARE_ETD(_tc, _e, 2); \
499 ed->data[0] = _timer_id; \
500 ed->data[1] = _timer_id; \
501 } \
502 else \
503 { \
Florin Coras6534b7a2017-07-18 05:38:03 -0400504 clib_warning ("pop %d for unexisting connection %d", _timer_id, \
505 _tc_index); \
Dave Barach2c25a622017-06-26 11:35:07 -0400506 } \
Florin Corase69f4952017-03-07 10:06:24 -0800507}
508
Florin Coras6792ec02017-03-13 03:49:51 -0700509#define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...) \
510{ \
511 ELOG_TYPE_DECLARE (_e) = \
512 { \
Florin Coras3e350af2017-03-30 02:54:28 -0700513 .format = "seg-inv: seq %u end %u rcv_las %u rcv_nxt %u rcv_wnd %u",\
Florin Coras6792ec02017-03-13 03:49:51 -0700514 .format_args = "i4i4i4i4i4", \
515 }; \
516 DECLARE_ETD(_tc, _e, 5); \
517 ed->data[0] = _seq - _tc->irs; \
518 ed->data[1] = _end - _tc->irs; \
519 ed->data[2] = _tc->rcv_las - _tc->irs; \
520 ed->data[3] = _tc->rcv_nxt - _tc->irs; \
521 ed->data[4] = _tc->rcv_wnd; \
522}
523
Florin Corasc28764f2017-04-26 00:08:42 -0700524#define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...) \
525{ \
526 ELOG_TYPE_DECLARE (_e) = \
527 { \
Florin Coras6534b7a2017-07-18 05:38:03 -0400528 .format = "paws-err: seq %u end %u tsval %u tsval_recent %u", \
Florin Corasc28764f2017-04-26 00:08:42 -0700529 .format_args = "i4i4i4i4", \
530 }; \
531 DECLARE_ETD(_tc, _e, 4); \
532 ed->data[0] = _seq - _tc->irs; \
533 ed->data[1] = _end - _tc->irs; \
Florin Coras93992a92017-05-24 18:03:56 -0700534 ed->data[2] = _tc->rcv_opts.tsval; \
Florin Corasc28764f2017-04-26 00:08:42 -0700535 ed->data[3] = _tc->tsval_recent; \
536}
537
Florin Coras6792ec02017-03-13 03:49:51 -0700538#define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...) \
539{ \
540 ELOG_TYPE_DECLARE (_e) = \
541 { \
542 .format = "ack-err: %s ack %u snd_una %u snd_nxt %u una_max %u", \
543 .format_args = "t4i4i4i4i4", \
544 .n_enum_strings = 3, \
545 .enum_strings = { \
546 "invalid", \
547 "old", \
548 "future", \
549 }, \
550 }; \
551 DECLARE_ETD(_tc, _e, 5); \
552 ed->data[0] = _type; \
553 ed->data[1] = _ack - _tc->iss; \
554 ed->data[2] = _tc->snd_una - _tc->iss; \
555 ed->data[3] = _tc->snd_nxt - _tc->iss; \
556 ed->data[4] = _tc->snd_una_max - _tc->iss; \
557}
558
Florin Corasf03a59a2017-06-09 21:07:32 -0700559#define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...) \
560{ \
561if (_av > 0) \
562{ \
563 ELOG_TYPE_DECLARE (_e) = \
564 { \
565 .format = "huh?: rcv_wnd %u obsd %u av %u rcv_nxt %u rcv_las %u", \
566 .format_args = "i4i4i4i4i4", \
567 }; \
568 DECLARE_ETD(_tc, _e, 5); \
569 ed->data[0] = _tc->rcv_wnd; \
570 ed->data[1] = _obs; \
571 ed->data[2] = _av; \
572 ed->data[3] = _tc->rcv_nxt - _tc->irs; \
573 ed->data[4] = _tc->rcv_las - _tc->irs; \
574} \
575}
576#else
577#define TCP_EVT_ACK_SENT_HANDLER(_tc, ...)
Florin Corasf03a59a2017-06-09 21:07:32 -0700578#define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...)
Florin Corasf03a59a2017-06-09 21:07:32 -0700579#define TCP_EVT_PKTIZE_HANDLER(_tc, ...)
580#define TCP_EVT_INPUT_HANDLER(_tc, _type, _len, _written, ...)
581#define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...)
582#define TCP_EVT_SEG_INVALID_HANDLER(_tc, _seq, _end, ...)
583#define TCP_EVT_PAWS_FAIL_HANDLER(_tc, _seq, _end, ...)
584#define TCP_EVT_ACK_RCV_ERR_HANDLER(_tc, _type, _ack, ...)
585#define TCP_EVT_RCV_WND_SHRUNK_HANDLER(_tc, _obs, _av, ...)
586#endif
587
588/*
589 * State machine verbose
590 */
Florin Coras6534b7a2017-07-18 05:38:03 -0400591#if TCP_DEBUG_SM > 2
Florin Corasf03a59a2017-06-09 21:07:32 -0700592#define TCP_EVT_SND_WND_HANDLER(_tc, ...) \
593{ \
594 ELOG_TYPE_DECLARE (_e) = \
595 { \
Florin Coras6534b7a2017-07-18 05:38:03 -0400596 .format = "snd-wnd update: %u ", \
Florin Corasf03a59a2017-06-09 21:07:32 -0700597 .format_args = "i4", \
598 }; \
599 DECLARE_ETD(_tc, _e, 1); \
600 ed->data[0] = _tc->snd_wnd; \
601}
602
603#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...) \
604{ \
605 ELOG_TYPE_DECLARE (_e) = \
606 { \
607 .format = "out: flags %x, bytes %u", \
608 .format_args = "i4i4", \
609 }; \
610 DECLARE_ETD(_tc, _e, 2); \
611 ed->data[0] = flags; \
612 ed->data[1] = n_bytes; \
613}
614#else
615#define TCP_EVT_SND_WND_HANDLER(_tc, ...)
616#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...)
617#endif
618
Florin Coras6792ec02017-03-13 03:49:51 -0700619/*
620 * Congestion Control
621 */
622
623#if TCP_DEBUG_CC
Florin Corasf1762d62017-09-24 19:43:08 -0400624
625#define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...) \
626{ \
627 ELOG_TYPE_DECLARE (_e) = \
628 { \
629 .format = "cc: %s wnd %u snd_cong %u rxt_bytes %u", \
630 .format_args = "t4i4i4i4", \
631 .n_enum_strings = 6, \
632 .enum_strings = { \
633 "fast-rxt", \
634 "rxt-timeout", \
635 "first-rxt", \
636 "recovered", \
637 "congestion", \
638 "undo", \
639 }, \
640 }; \
641 DECLARE_ETD(_tc, _e, 4); \
642 ed->data[0] = _sub_evt; \
643 ed->data[1] = tcp_available_snd_space (_tc); \
644 ed->data[2] = _tc->snd_congestion - _tc->iss; \
645 ed->data[3] = _tc->snd_rxt_bytes; \
646}
647
Florin Coras6792ec02017-03-13 03:49:51 -0700648#define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...) \
649{ \
650 ELOG_TYPE_DECLARE (_e) = \
651 { \
Florin Coras93992a92017-05-24 18:03:56 -0700652 .format = "rxt: snd_nxt %u offset %u snd %u rxt %u", \
Florin Coras6792ec02017-03-13 03:49:51 -0700653 .format_args = "i4i4i4i4", \
654 }; \
655 DECLARE_ETD(_tc, _e, 4); \
656 ed->data[0] = _tc->snd_nxt - _tc->iss; \
657 ed->data[1] = offset; \
658 ed->data[2] = n_bytes; \
Florin Coras93992a92017-05-24 18:03:56 -0700659 ed->data[3] = _tc->snd_rxt_bytes; \
Florin Coras6792ec02017-03-13 03:49:51 -0700660}
661
Florin Corasf1762d62017-09-24 19:43:08 -0400662#define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...) \
Florin Coras6792ec02017-03-13 03:49:51 -0700663{ \
664 ELOG_TYPE_DECLARE (_e) = \
665 { \
Florin Corasf1762d62017-09-24 19:43:08 -0400666 .format = "dack-tx: rcv_nxt %u rcv_wnd %u snd_nxt %u av_wnd %u snd_wnd %u",\
667 .format_args = "i4i4i4i4i4", \
Florin Coras6792ec02017-03-13 03:49:51 -0700668 }; \
Florin Corasf1762d62017-09-24 19:43:08 -0400669 DECLARE_ETD(_tc, _e, 5); \
670 ed->data[0] = _tc->rcv_nxt - _tc->irs; \
671 ed->data[1] = _tc->rcv_wnd; \
672 ed->data[2] = _tc->snd_nxt - _tc->iss; \
673 ed->data[3] = tcp_available_snd_wnd(_tc); \
674 ed->data[4] = _tc->snd_wnd; \
675}
676
677#define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...) \
678{ \
679 ELOG_TYPE_DECLARE (_e) = \
680 { \
681 .format = "dack-rx: snd_una %u cwnd %u snd_wnd %u flight %u rcv_wnd %u",\
682 .format_args = "i4i4i4i4i4", \
683 }; \
684 DECLARE_ETD(_tc, _e, 5); \
685 ed->data[0] = _tc->snd_una - _tc->iss; \
686 ed->data[1] = _tc->cwnd; \
687 ed->data[2] = _tc->snd_wnd; \
688 ed->data[3] = tcp_flight_size(_tc); \
689 ed->data[4] = _tc->rcv_wnd; \
Florin Coras6792ec02017-03-13 03:49:51 -0700690}
691
692#define TCP_EVT_CC_PACK_HANDLER(_tc, ...) \
693{ \
694 ELOG_TYPE_DECLARE (_e) = \
695 { \
696 .format = "pack: snd_una %u snd_una_max %u", \
697 .format_args = "i4i4", \
698 }; \
699 DECLARE_ETD(_tc, _e, 2); \
700 ed->data[0] = _tc->snd_una - _tc->iss; \
701 ed->data[1] = _tc->snd_una_max - _tc->iss; \
702}
Florin Corasf1762d62017-09-24 19:43:08 -0400703#else
704#define TCP_EVT_CC_RTX_HANDLER(_tc, offset, n_bytes, ...)
705#define TCP_EVT_DUPACK_SENT_HANDLER(_tc, ...)
706#define TCP_EVT_DUPACK_RCVD_HANDLER(_tc, ...)
707#define TCP_EVT_CC_PACK_HANDLER(_tc, ...)
708#define TCP_EVT_CC_EVT_HANDLER(_tc, _sub_evt, ...)
709#endif
Florin Coras6792ec02017-03-13 03:49:51 -0700710
Florin Corasf03a59a2017-06-09 21:07:32 -0700711/*
712 * Congestion control stats
713 */
714#if TCP_DEBUG_CC_STAT
Florin Coras6792ec02017-03-13 03:49:51 -0700715
Florin Corasf03a59a2017-06-09 21:07:32 -0700716#define STATS_INTERVAL 1
717
718#define TCP_EVT_CC_RTO_STAT_HANDLER(_tc, ...) \
Florin Coras3e350af2017-03-30 02:54:28 -0700719{ \
Florin Corasf03a59a2017-06-09 21:07:32 -0700720if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()) \
Florin Coras3e350af2017-03-30 02:54:28 -0700721{ \
722 ELOG_TYPE_DECLARE (_e) = \
723 { \
Florin Coras62166002018-04-18 16:40:55 -0700724 .format = "rcv_stat: rto %u srtt %u rttvar %u ", \
Florin Corasf03a59a2017-06-09 21:07:32 -0700725 .format_args = "i4i4i4", \
Florin Coras3e350af2017-03-30 02:54:28 -0700726 }; \
Florin Corasf03a59a2017-06-09 21:07:32 -0700727 DECLARE_ETD(_tc, _e, 3); \
728 ed->data[0] = _tc->rto; \
729 ed->data[1] = _tc->srtt; \
730 ed->data[2] = _tc->rttvar; \
Florin Coras3e350af2017-03-30 02:54:28 -0700731} \
732}
Florin Coras62166002018-04-18 16:40:55 -0700733#define TCP_EVT_CC_SND_STAT_HANDLER(_tc, ...) \
734{ \
735if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()) \
736{ \
737 ELOG_TYPE_DECLARE (_e) = \
738 { \
739 .format = "snd_stat: dack %u sacked %u lost %u out %u rxt %u", \
740 .format_args = "i4i4i4i4i4", \
741 }; \
742 DECLARE_ETD(_tc, _e, 5); \
743 ed->data[0] = _tc->rcv_dupacks; \
744 ed->data[1] = _tc->sack_sb.sacked_bytes; \
745 ed->data[2] = _tc->sack_sb.lost_bytes; \
746 ed->data[3] = tcp_bytes_out (_tc); \
747 ed->data[3] = _tc->snd_rxt_bytes; \
748} \
749}
Florin Coras3e350af2017-03-30 02:54:28 -0700750
Florin Corasf03a59a2017-06-09 21:07:32 -0700751#define TCP_EVT_CC_STAT_HANDLER(_tc, ...) \
752{ \
753if (_tc->c_cc_stat_tstamp + STATS_INTERVAL < tcp_time_now()) \
Florin Coras6792ec02017-03-13 03:49:51 -0700754{ \
755 ELOG_TYPE_DECLARE (_e) = \
756 { \
Florin Corasf03a59a2017-06-09 21:07:32 -0700757 .format = "cc_stat: cwnd %u flight %u space %u ssthresh %u snd_wnd %u",\
758 .format_args = "i4i4i4i4i4", \
Florin Coras6792ec02017-03-13 03:49:51 -0700759 }; \
Florin Corasf03a59a2017-06-09 21:07:32 -0700760 DECLARE_ETD(_tc, _e, 5); \
761 ed->data[0] = _tc->cwnd; \
762 ed->data[1] = tcp_flight_size (_tc); \
763 ed->data[2] = tcp_snd_space (_tc); \
764 ed->data[3] = _tc->ssthresh; \
765 ed->data[4] = _tc->snd_wnd; \
766 TCP_EVT_CC_RTO_STAT_HANDLER (_tc); \
767 _tc->c_cc_stat_tstamp = tcp_time_now(); \
768} \
Florin Coras6792ec02017-03-13 03:49:51 -0700769}
770
Florin Corasf988e692017-11-27 04:34:14 -0500771/*
772 * Buffer allocation
773 */
774#if TCP_DEBUG_BUFFER_ALLOCATION
775
776#define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index) \
777{ \
778 static u32 *buffer_fail_counters; \
779 if (PREDICT_FALSE (buffer_fail_counters == 0)) \
780 { \
781 u32 num_threads; \
782 vlib_thread_main_t *vtm = vlib_get_thread_main (); \
783 num_threads = 1 /* main thread */ + vtm->n_threads; \
784 vec_validate (buffer_fail_counters, num_threads - 1); \
785 } \
786 if (PREDICT_FALSE (tcp_main.buffer_fail_fraction != 0.0)) \
787 { \
788 if (PREDICT_TRUE (buffer_fail_counters[thread_index] > 0)) \
789 { \
790 if ((1.0 / (f32) (buffer_fail_counters[thread_index])) \
791 < tcp_main.buffer_fail_fraction) \
792 { \
793 buffer_fail_counters[thread_index] = 0.0000001; \
794 return -1; \
795 } \
796 } \
797 buffer_fail_counters[thread_index] ++; \
798 } \
799}
800#else
801#define TCP_DBG_BUFFER_ALLOC_MAYBE_FAIL(thread_index)
802#endif
803
Florin Coras6792ec02017-03-13 03:49:51 -0700804#else
Florin Corasf03a59a2017-06-09 21:07:32 -0700805#define TCP_EVT_CC_STAT_HANDLER(_tc, ...)
Florin Coras6792ec02017-03-13 03:49:51 -0700806#endif
807
Florin Corase69f4952017-03-07 10:06:24 -0800808#endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
809/*
810 * fd.io coding-style-patch-verification: ON
811 *
812 * Local Variables:
813 * eval: (c-set-style "gnu")
814 * End:
815 */