VPP-659 Improve tcp/session debugging and testing
- event-logging support for tcp and session layer
- improvements to uri test code
- builtin_server on port 1234
- use the CLOSEWAIT timer when we rx FIN in FIN_WAIT_2 state
Change-Id: Ibc445f164b2086b20323bf89c77cffd3059f570f
Signed-off-by: Florin Coras <fcoras@cisco.com>
Signed-off-by: Dave Barach <dbarach@cisco.com>
Signed-off-by: Dave Barach <dave@barachs.net>
diff --git a/src/vnet/tcp/builtin_server.c b/src/vnet/tcp/builtin_server.c
index 9b697a0..dd6759c 100644
--- a/src/vnet/tcp/builtin_server.c
+++ b/src/vnet/tcp/builtin_server.c
@@ -160,7 +160,7 @@
memset (a, 0, sizeof (*a));
memset (options, 0, sizeof (options));
- a->uri = "tcp://0.0.0.0/80";
+ a->uri = "tcp://0.0.0.0/1234";
a->api_client_index = ~0;
a->session_cb_vft = &builtin_session_cb_vft;
a->options = options;
diff --git a/src/vnet/tcp/tcp.c b/src/vnet/tcp/tcp.c
index d2df5c3..0d2e6d0 100644
--- a/src/vnet/tcp/tcp.c
+++ b/src/vnet/tcp/tcp.c
@@ -21,7 +21,7 @@
tcp_main_t tcp_main;
static u32
-tcp_connection_bind (vlib_main_t * vm, u32 session_index, ip46_address_t * ip,
+tcp_connection_bind (u32 session_index, ip46_address_t * ip,
u16 port_host_byte_order, u8 is_ip4)
{
tcp_main_t *tm = &tcp_main;
@@ -43,42 +43,41 @@
listener->state = TCP_STATE_LISTEN;
listener->c_is_ip4 = 1;
+ tcp_connection_timers_init (listener);
+
+ TCP_EVT_DBG (TCP_EVT_BIND, listener);
+
return listener->c_c_index;
}
u32
-tcp_session_bind_ip4 (vlib_main_t * vm, u32 session_index,
- ip46_address_t * ip, u16 port_host_byte_order)
+tcp_session_bind_ip4 (u32 session_index, ip46_address_t * ip,
+ u16 port_host_byte_order)
{
- return tcp_connection_bind (vm, session_index, ip, port_host_byte_order, 1);
+ return tcp_connection_bind (session_index, ip, port_host_byte_order, 1);
}
u32
-tcp_session_bind_ip6 (vlib_main_t * vm, u32 session_index,
- ip46_address_t * ip, u16 port_host_byte_order)
+tcp_session_bind_ip6 (u32 session_index, ip46_address_t * ip,
+ u16 port_host_byte_order)
{
- return tcp_connection_bind (vm, session_index, ip, port_host_byte_order, 0);
+ return tcp_connection_bind (session_index, ip, port_host_byte_order, 0);
}
static void
-tcp_session_unbind (u32 listener_index)
+tcp_connection_unbind (u32 listener_index)
{
tcp_main_t *tm = vnet_get_tcp_main ();
+ TCP_EVT_DBG (TCP_EVT_UNBIND,
+ pool_elt_at_index (tm->listener_pool, listener_index));
pool_put_index (tm->listener_pool, listener_index);
}
u32
-tcp_session_unbind_ip4 (vlib_main_t * vm, u32 listener_index)
+tcp_session_unbind (u32 listener_index)
{
- tcp_session_unbind (listener_index);
- return 0;
-}
-
-u32
-tcp_session_unbind_ip6 (vlib_main_t * vm, u32 listener_index)
-{
- tcp_session_unbind (listener_index);
+ tcp_connection_unbind (listener_index);
return 0;
}
@@ -135,6 +134,7 @@
void
tcp_connection_del (tcp_connection_t * tc)
{
+ TCP_EVT_DBG (TCP_EVT_DELETE, tc);
stream_session_delete_notify (&tc->connection);
tcp_connection_cleanup (tc);
}
@@ -169,6 +169,8 @@
void
tcp_connection_close (tcp_connection_t * tc)
{
+ TCP_EVT_DBG (TCP_EVT_CLOSE, tc);
+
/* Send FIN if needed */
if (tc->state == TCP_STATE_ESTABLISHED || tc->state == TCP_STATE_SYN_RCVD
|| tc->state == TCP_STATE_CLOSE_WAIT)
@@ -403,6 +405,8 @@
tc->state = TCP_STATE_SYN_SENT;
+ TCP_EVT_DBG (TCP_EVT_OPEN, tc);
+
return tc->c_c_index;
}
@@ -418,82 +422,119 @@
return tcp_connection_open (addr, port, 0);
}
+const char *tcp_dbg_evt_str[] = {
+#define _(sym, str) str,
+ foreach_tcp_dbg_evt
+#undef _
+};
+
+const char *tcp_fsm_states[] = {
+#define _(sym, str) str,
+ foreach_tcp_fsm_state
+#undef _
+};
+
u8 *
-format_tcp_session_ip4 (u8 * s, va_list * args)
+format_tcp_state (u8 * s, va_list * args)
+{
+ tcp_state_t *state = va_arg (*args, tcp_state_t *);
+
+ if (*state < TCP_N_STATES)
+ s = format (s, "%s", tcp_fsm_states[*state]);
+ else
+ s = format (s, "UNKNOWN");
+
+ return s;
+}
+
+const char *tcp_conn_timers[] = {
+#define _(sym, str) str,
+ foreach_tcp_timer
+#undef _
+};
+
+u8 *
+format_tcp_timers (u8 * s, va_list * args)
+{
+ tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+ int i, last = 0;
+
+ for (i = 0; i < TCP_N_TIMERS; i++)
+ if (tc->timers[i] != TCP_TIMER_HANDLE_INVALID)
+ last = i;
+
+ s = format (s, "[");
+ for (i = 0; i < last; i++)
+ {
+ if (tc->timers[i] != TCP_TIMER_HANDLE_INVALID)
+ s = format (s, "%s,", tcp_conn_timers[i]);
+ }
+
+ if (last > 0)
+ s = format (s, "%s]", tcp_conn_timers[i]);
+ else
+ s = format (s, "]");
+
+ return s;
+}
+
+u8 *
+format_tcp_connection (u8 * s, va_list * args)
+{
+ tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+
+ if (tc->c_is_ip4)
+ {
+ s = format (s, "[#%d][%s] %U:%d->%U:%d", tc->c_thread_index, "T",
+ format_ip4_address, &tc->c_lcl_ip4,
+ clib_net_to_host_u16 (tc->c_lcl_port), format_ip4_address,
+ &tc->c_rmt_ip4, clib_net_to_host_u16 (tc->c_rmt_port));
+ }
+ else
+ {
+ s = format (s, "[#%d][%s] %U:%d->%U:%d", tc->c_thread_index, "T",
+ format_ip6_address, &tc->c_lcl_ip6,
+ clib_net_to_host_u16 (tc->c_lcl_port), format_ip6_address,
+ &tc->c_rmt_ip6, clib_net_to_host_u16 (tc->c_rmt_port));
+ }
+
+ return s;
+}
+
+u8 *
+format_tcp_connection_verbose (u8 * s, va_list * args)
+{
+ tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+ s = format (s, "%U %U %U", format_tcp_connection, tc, format_tcp_state,
+ &tc->state, format_tcp_timers, tc);
+ return s;
+}
+
+u8 *
+format_tcp_session (u8 * s, va_list * args)
{
u32 tci = va_arg (*args, u32);
u32 thread_index = va_arg (*args, u32);
tcp_connection_t *tc;
tc = tcp_connection_get (tci, thread_index);
-
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
- &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip4_address, &tc->c_rmt_ip4,
- clib_net_to_host_u16 (tc->c_rmt_port));
-
- return s;
+ return format (s, "%U", format_tcp_connection, tc);
}
u8 *
-format_tcp_session_ip6 (u8 * s, va_list * args)
-{
- u32 tci = va_arg (*args, u32);
- u32 thread_index = va_arg (*args, u32);
- tcp_connection_t *tc = tcp_connection_get (tci, thread_index);
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
- &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip6_address, &tc->c_rmt_ip6,
- clib_net_to_host_u16 (tc->c_rmt_port));
- return s;
-}
-
-u8 *
-format_tcp_listener_session_ip4 (u8 * s, va_list * args)
+format_tcp_listener_session (u8 * s, va_list * args)
{
u32 tci = va_arg (*args, u32);
tcp_connection_t *tc = tcp_listener_get (tci);
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
- &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip4_address, &tc->c_rmt_ip4,
- clib_net_to_host_u16 (tc->c_rmt_port));
- return s;
+ return format (s, "%U", format_tcp_connection, tc);
}
u8 *
-format_tcp_listener_session_ip6 (u8 * s, va_list * args)
-{
- u32 tci = va_arg (*args, u32);
- tcp_connection_t *tc = tcp_listener_get (tci);
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
- &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip6_address, &tc->c_rmt_ip6,
- clib_net_to_host_u16 (tc->c_rmt_port));
- return s;
-}
-
-u8 *
-format_tcp_half_open_session_ip4 (u8 * s, va_list * args)
+format_tcp_half_open_session (u8 * s, va_list * args)
{
u32 tci = va_arg (*args, u32);
tcp_connection_t *tc = tcp_half_open_connection_get (tci);
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip4_address,
- &tc->c_lcl_ip4, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip4_address, &tc->c_rmt_ip4,
- clib_net_to_host_u16 (tc->c_rmt_port));
- return s;
-}
-
-u8 *
-format_tcp_half_open_session_ip6 (u8 * s, va_list * args)
-{
- u32 tci = va_arg (*args, u32);
- tcp_connection_t *tc = tcp_half_open_connection_get (tci);
- s = format (s, "[%s] %U:%d->%U:%d", "tcp", format_ip6_address,
- &tc->c_lcl_ip6, clib_net_to_host_u16 (tc->c_lcl_port),
- format_ip6_address, &tc->c_rmt_ip6,
- clib_net_to_host_u16 (tc->c_rmt_port));
- return s;
+ return format (s, "%U", format_tcp_connection, tc);
}
transport_connection_t *
@@ -534,7 +575,7 @@
/* *INDENT-OFF* */
const static transport_proto_vft_t tcp4_proto = {
.bind = tcp_session_bind_ip4,
- .unbind = tcp_session_unbind_ip4,
+ .unbind = tcp_session_unbind,
.push_header = tcp_push_header,
.get_connection = tcp_session_get_transport,
.get_listener = tcp_session_get_listener,
@@ -545,14 +586,14 @@
.send_mss = tcp_session_send_mss,
.send_space = tcp_session_send_space,
.tx_fifo_offset = tcp_session_tx_fifo_offset,
- .format_connection = format_tcp_session_ip4,
- .format_listener = format_tcp_listener_session_ip4,
- .format_half_open = format_tcp_half_open_session_ip4
+ .format_connection = format_tcp_session,
+ .format_listener = format_tcp_listener_session,
+ .format_half_open = format_tcp_half_open_session,
};
const static transport_proto_vft_t tcp6_proto = {
.bind = tcp_session_bind_ip6,
- .unbind = tcp_session_unbind_ip6,
+ .unbind = tcp_session_unbind,
.push_header = tcp_push_header,
.get_connection = tcp_session_get_transport,
.get_listener = tcp_session_get_listener,
@@ -563,9 +604,9 @@
.send_mss = tcp_session_send_mss,
.send_space = tcp_session_send_space,
.tx_fifo_offset = tcp_session_tx_fifo_offset,
- .format_connection = format_tcp_session_ip6,
- .format_listener = format_tcp_listener_session_ip6,
- .format_half_open = format_tcp_half_open_session_ip6
+ .format_connection = format_tcp_session,
+ .format_listener = format_tcp_listener_session,
+ .format_half_open = format_tcp_half_open_session,
};
/* *INDENT-ON* */
@@ -654,6 +695,8 @@
connection_index = expired_timers[i] & 0x0FFFFFFF;
timer_id = expired_timers[i] >> 28;
+ TCP_EVT_DBG (TCP_EVT_TIMER_POP, connection_index, timer_id);
+
/* Handle expiration */
(*timer_expiration_handlers[timer_id]) (connection_index);
}
diff --git a/src/vnet/tcp/tcp.h b/src/vnet/tcp/tcp.h
index 3b3d8fc..082ab1d 100644
--- a/src/vnet/tcp/tcp.h
+++ b/src/vnet/tcp/tcp.h
@@ -22,6 +22,7 @@
#include <vnet/tcp/tcp_timer.h>
#include <vnet/session/transport.h>
#include <vnet/session/session.h>
+#include <vnet/tcp/tcp_debug.h>
#define TCP_TICK 10e-3 /**< TCP tick period (s) */
#define THZ 1/TCP_TICK /**< TCP tick frequency */
@@ -222,7 +223,7 @@
u32 prev_ssthresh; /**< ssthresh before congestion */
u32 bytes_acked; /**< Bytes acknowledged by current segment */
u32 rtx_bytes; /**< Retransmitted bytes */
- u32 tsecr_last_ack; /**< Timestamp echoed to us in last health ACK */
+ u32 tsecr_last_ack; /**< Timestamp echoed to us in last healthy ACK */
tcp_cc_algorithm_t *cc_algo; /**< Congestion control algorithm */
/* RTT and RTO */
@@ -354,6 +355,9 @@
void tcp_connection_del (tcp_connection_t * tc);
void tcp_connection_reset (tcp_connection_t * tc);
+u8 *format_tcp_connection (u8 * s, va_list * args);
+u8 *format_tcp_connection_verbose (u8 * s, va_list * args);
+
always_inline tcp_connection_t *
tcp_listener_get (u32 tli)
{
diff --git a/src/vnet/tcp/tcp_debug.h b/src/vnet/tcp/tcp_debug.h
new file mode 100644
index 0000000..069c512
--- /dev/null
+++ b/src/vnet/tcp/tcp_debug.h
@@ -0,0 +1,316 @@
+/*
+ * Copyright (c) 2017 Cisco and/or its affiliates.
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at:
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef SRC_VNET_TCP_TCP_DEBUG_H_
+#define SRC_VNET_TCP_TCP_DEBUG_H_
+
+#include <vlib/vlib.h>
+
+#define TCP_DEBUG (1)
+
+#define foreach_tcp_dbg_evt \
+ _(INIT, "") \
+ _(DEALLOC, "") \
+ _(OPEN, "open") \
+ _(CLOSE, "close") \
+ _(BIND, "bind") \
+ _(UNBIND, "unbind") \
+ _(DELETE, "delete") \
+ _(SYN_SENT, "SYN sent") \
+ _(FIN_SENT, "FIN sent") \
+ _(RST_SENT, "RST sent") \
+ _(SYN_RCVD, "SYN rcvd") \
+ _(ACK_RCVD, "ACK rcvd") \
+ _(FIN_RCVD, "FIN rcvd") \
+ _(RST_RCVD, "RST rcvd") \
+ _(PKTIZE, "packetize") \
+ _(INPUT, "in") \
+ _(TIMER_POP, "timer pop")
+
+typedef enum _tcp_dbg
+{
+#define _(sym, str) TCP_DBG_##sym,
+ foreach_tcp_dbg_evt
+#undef _
+} tcp_dbg_e;
+
+typedef enum _tcp_dbg_evt
+{
+#define _(sym, str) TCP_EVT_##sym,
+ foreach_tcp_dbg_evt
+#undef _
+} tcp_dbg_evt_e;
+
+#if TCP_DEBUG
+
+#define TRANSPORT_DEBUG (1)
+
+#define TCP_DBG(_tc, _evt, _args...) \
+{ \
+ u8 *_tmp = 0; \
+ _tmp = format(_tmp, "%U", format_tcp_connection_verbose, _tc); \
+ clib_warning("%s", _tmp); \
+ vec_free(_tmp); \
+}
+
+#define DECLARE_ETD(_tc, _e, _size) \
+ struct \
+ { \
+ u32 data[_size]; \
+ } * ed; \
+ ed = ELOG_TRACK_DATA (&vlib_global_main.elog_main, \
+ _e, _tc->c_elog_track)
+
+#define TCP_EVT_INIT_HANDLER(_tc, ...) \
+{ \
+ _tc->c_elog_track.name = \
+ (char *) format (0, "%d%c", _tc->c_c_index, 0); \
+ elog_track_register (&vlib_global_main.elog_main, &_tc->c_elog_track);\
+}
+
+#define TCP_EVT_DEALLOC_HANDLER(_tc, ...) \
+{ \
+ vec_free (_tc->c_elog_track.name); \
+}
+
+#define TCP_EVT_OPEN_HANDLER(_tc, ...) \
+{ \
+ TCP_EVT_INIT_HANDLER(_tc); \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "open: index %d", \
+ .format_args = "i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->c_c_index; \
+}
+
+#define TCP_EVT_CLOSE_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "close: %d", \
+ .format_args = "i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->c_c_index; \
+}
+
+#define TCP_EVT_BIND_HANDLER(_tc, ...) \
+{ \
+ TCP_EVT_INIT_HANDLER(_tc); \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "bind: listener %d", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->c_c_index; \
+}
+
+#define TCP_EVT_UNBIND_HANDLER(_tc, ...) \
+{ \
+ TCP_EVT_DEALLOC_HANDLER(_tc); \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "unbind: listener %d", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->c_c_index; \
+ TCP_EVT_DEALLOC_HANDLER(_tc); \
+}
+
+#define TCP_EVT_DELETE_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "delete: %d", \
+ .format_args = "i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 0); \
+ ed->data[0] = _tc->c_c_index; \
+ TCP_EVT_DEALLOC_HANDLER(_tc); \
+}
+
+#define TCP_EVT_SYN_SENT_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "SYN: iss %d", \
+ .format_args = "i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->iss; \
+}
+
+#define TCP_EVT_FIN_SENT_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "FIN: snd_nxt %d rcv_nxt %d", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = _tc->snd_nxt - _tc->iss; \
+ ed->data[1] = _tc->rcv_nxt - _tc->irs; \
+}
+
+#define TCP_EVT_RST_SENT_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "RST: snd_nxt %d rcv_nxt %d", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = _tc->snd_nxt - _tc->iss; \
+ ed->data[1] = _tc->rcv_nxt - _tc->irs; \
+}
+
+#define TCP_EVT_SYN_RCVD_HANDLER(_tc, ...) \
+{ \
+ TCP_EVT_INIT_HANDLER(_tc); \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "SYN rcvd: irs %d", \
+ .format_args = "i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 1); \
+ ed->data[0] = _tc->irs; \
+}
+
+#define TCP_EVT_FIN_RCVD_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "FIN rcvd: snd_nxt %d rcv_nxt %d", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = _tc->snd_nxt - _tc->iss; \
+ ed->data[1] = _tc->rcv_nxt - _tc->irs; \
+}
+
+#define TCP_EVT_RST_RCVD_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "RST rcvd: snd_nxt %d rcv_nxt %d", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = _tc->snd_nxt - _tc->iss; \
+ ed->data[1] = _tc->rcv_nxt - _tc->irs; \
+}
+
+#define TCP_EVT_ACK_RCVD_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "ACK: acked %u cwnd %u inflight %u", \
+ .format_args = "i4i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 3); \
+ ed->data[0] = _tc->bytes_acked; \
+ ed->data[1] = _tc->cwnd; \
+ ed->data[2] = tcp_flight_size(_tc); \
+}
+
+#define TCP_EVT_PKTIZE_HANDLER(_tc, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "pktize: snd_una %u snd_nxt %u una_max %u", \
+ .format_args = "i4i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 3); \
+ ed->data[0] = _tc->snd_una - _tc->iss; \
+ ed->data[1] = _tc->snd_nxt - _tc->iss; \
+ ed->data[2] = _tc->snd_una_max - _tc->iss; \
+}
+
+#define TCP_EVT_OUTPUT_HANDLER(_tc, flags, n_bytes,...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "out: flags %x, bytes %u", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = flags; \
+ ed->data[1] = n_bytes; \
+}
+
+#define TCP_EVT_INPUT_HANDLER(_tc, n_bytes, ...) \
+{ \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "in: bytes %u rcv_nxt %u", \
+ .format_args = "i4i4", \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = n_bytes; \
+ ed->data[1] = _tc->rcv_nxt - _tc->irs; \
+}
+
+#define TCP_EVT_TIMER_POP_HANDLER(_tc_index, _timer_id, ...) \
+{ \
+ tcp_connection_t *_tc; \
+ if (_timer_id == TCP_TIMER_RETRANSMIT_SYN) \
+ { \
+ _tc = tcp_half_open_connection_get (_tc_index); \
+ } \
+ else \
+ { \
+ u32 _thread_index = os_get_cpu_number (); \
+ _tc = tcp_connection_get (_tc_index, _thread_index); \
+ } \
+ ELOG_TYPE_DECLARE (_e) = \
+ { \
+ .format = "TimerPop: %s (%d)", \
+ .format_args = "t4i4", \
+ .n_enum_strings = 7, \
+ .enum_strings = { \
+ "retransmit", \
+ "delack", \
+ "BUG", \
+ "keep", \
+ "waitclose", \
+ "retransmit syn", \
+ "establish", \
+ }, \
+ }; \
+ DECLARE_ETD(_tc, _e, 2); \
+ ed->data[0] = _timer_id; \
+ ed->data[1] = _timer_id; \
+}
+
+#define CONCAT_HELPER(_a, _b) _a##_b
+#define CC(_a, _b) CONCAT_HELPER(_a, _b)
+
+#define TCP_EVT_DBG(_evt, _args...) CC(_evt, _HANDLER)(_args)
+
+#else
+#define TCP_EVT_DBG(_evt, _args...)
+#endif
+
+
+#endif /* SRC_VNET_TCP_TCP_DEBUG_H_ */
+/*
+ * fd.io coding-style-patch-verification: ON
+ *
+ * Local Variables:
+ * eval: (c-set-style "gnu")
+ * End:
+ */
diff --git a/src/vnet/tcp/tcp_input.c b/src/vnet/tcp/tcp_input.c
index f19fbf8..67af432 100644
--- a/src/vnet/tcp/tcp_input.c
+++ b/src/vnet/tcp/tcp_input.c
@@ -730,6 +730,8 @@
/* Updates congestion control (slow start/congestion avoidance) */
tcp_cc_rcv_ack (tc);
+ TCP_EVT_DBG (TCP_EVT_ACK_RCVD, tc);
+
/* If everything has been acked, stop retransmit timer
* otherwise update */
if (tc->snd_una == tc->snd_una_max)
@@ -922,6 +924,8 @@
* segments can be enqueued after fifo tail offset changes. */
error = tcp_session_enqueue_data (tc, b, n_data_bytes);
+ TCP_EVT_DBG (TCP_EVT_INPUT, tc, n_data_bytes);
+
/* Check if ACK can be delayed */
if (tcp_can_delack (tc))
{
@@ -1079,6 +1083,7 @@
* wait for session to call close. To avoid lingering
* in CLOSE-WAIT, set timer (reuse WAITCLOSE). */
tc0->state = TCP_STATE_CLOSE_WAIT;
+ TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc0);
stream_session_disconnect_notify (&tc0->connection);
tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_CLOSEWAIT_TIME);
}
@@ -1134,7 +1139,8 @@
.name = "tcp4-established",
/* Takes a vector of packets. */
.vector_size = sizeof (u32),
- .n_errors = TCP_N_ERROR,.error_strings = tcp_error_strings,
+ .n_errors = TCP_N_ERROR,
+ .error_strings = tcp_error_strings,
.n_next_nodes = TCP_ESTABLISHED_N_NEXT,
.next_nodes =
{
@@ -1363,7 +1369,7 @@
{
new_tc0->state = TCP_STATE_SYN_RCVD;
- /* Notify app that we have connection XXX */
+ /* Notify app that we have connection */
stream_session_connect_notify (&new_tc0->connection, sst, 0);
tcp_make_synack (new_tc0, b0);
@@ -1726,7 +1732,7 @@
case TCP_STATE_FIN_WAIT_2:
/* Got FIN, send ACK! */
tc0->state = TCP_STATE_TIME_WAIT;
- tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_2MSL_TIME);
+ tcp_timer_set (tc0, TCP_TIMER_WAITCLOSE, TCP_CLOSEWAIT_TIME);
tcp_make_ack (tc0, b0);
next0 = tcp_next_output (is_ip4);
break;
@@ -1737,6 +1743,7 @@
tcp_timer_update (tc0, TCP_TIMER_WAITCLOSE, TCP_2MSL_TIME);
break;
}
+ TCP_EVT_DBG (TCP_EVT_FIN_RCVD, tc0);
b0->error = error0 ? node->errors[error0] : 0;
@@ -1950,6 +1957,8 @@
tcp_connection_init_vars (child0);
+ TCP_EVT_DBG (TCP_EVT_SYN_RCVD, child0);
+
/* Reuse buffer to make syn-ack and send */
tcp_make_synack (child0, b0);
next0 = tcp_next_output (is_ip4);
@@ -2064,25 +2073,6 @@
u8 state;
} tcp_rx_trace_t;
-const char *tcp_fsm_states[] = {
-#define _(sym, str) str,
- foreach_tcp_fsm_state
-#undef _
-};
-
-u8 *
-format_tcp_state (u8 * s, va_list * args)
-{
- tcp_state_t *state = va_arg (*args, tcp_state_t *);
-
- if (state[0] < TCP_N_STATES)
- s = format (s, "%s", tcp_fsm_states[state[0]]);
- else
- s = format (s, "UNKNOWN");
-
- return s;
-}
-
u8 *
format_tcp_rx_trace (u8 * s, va_list * args)
{
diff --git a/src/vnet/tcp/tcp_output.c b/src/vnet/tcp/tcp_output.c
index aa43e9f..114a5b9 100644
--- a/src/vnet/tcp/tcp_output.c
+++ b/src/vnet/tcp/tcp_output.c
@@ -452,11 +452,7 @@
tcp_reuse_buffer (vm, b);
- if (tc->rcv_las == tc->rcv_nxt)
- flags = TCP_FLAG_FIN;
- else
- flags = TCP_FLAG_FIN | TCP_FLAG_ACK;
-
+ flags = TCP_FLAG_FIN | TCP_FLAG_ACK;
tcp_make_ack_i (tc, b, TCP_STATE_ESTABLISHED, flags);
/* Reset flags, make sure ack is sent */
@@ -828,6 +824,7 @@
tcp_make_fin (tc, b);
tcp_enqueue_to_output (vm, b, bi, tc->c_is_ip4);
tc->flags |= TCP_CONN_FINSNT;
+ TCP_EVT_DBG (TCP_EVT_FIN_SENT, tc);
}
always_inline u8
@@ -887,6 +884,7 @@
vnet_buffer (b)->tcp.connection_index = tc->c_c_index;
tc->snd_nxt += data_len;
+ TCP_EVT_DBG (TCP_EVT_PKTIZE, tc);
}
/* Send delayed ACK when timer expires */
@@ -1186,6 +1184,7 @@
}
th0 = vlib_buffer_get_current (b0);
+ TCP_EVT_DBG (TCP_EVT_OUTPUT, tc0, th0->flags, b0->current_length);
if (is_ip4)
{
@@ -1242,22 +1241,6 @@
tc0->rtt_ts = tcp_time_now ();
tc0->rtt_seq = tc0->snd_nxt;
}
-
- if (1)
- {
- ELOG_TYPE_DECLARE (e) =
- {
- .format =
- "output: snd_una %u snd_una_max %u",.format_args =
- "i4i4",};
- struct
- {
- u32 data[2];
- } *ed;
- ed = ELOG_DATA (&vm->elog_main, e);
- ed->data[0] = tc0->snd_una - tc0->iss;
- ed->data[1] = tc0->snd_una_max - tc0->iss;
- }
}
/* Set the retransmit timer if not set already and not
@@ -1275,9 +1258,8 @@
vnet_buffer (b0)->sw_if_index[VLIB_TX] = (u32) ~ 0;
b0->flags |= VNET_BUFFER_LOCALLY_ORIGINATED;
-
done:
- b0->error = error0 != 0 ? node->errors[error0] : 0;
+ b0->error = node->errors[error0];
if (PREDICT_FALSE (b0->flags & VLIB_BUFFER_IS_TRACED))
{
@@ -1307,34 +1289,50 @@
return tcp46_output_inline (vm, node, from_frame, 0 /* is_ip4 */ );
}
+/* *INDENT-OFF* */
VLIB_REGISTER_NODE (tcp4_output_node) =
{
.function = tcp4_output,.name = "tcp4-output",
/* Takes a vector of packets. */
- .vector_size = sizeof (u32),.n_errors = TCP_N_ERROR,.error_strings =
- tcp_error_strings,.n_next_nodes = TCP_OUTPUT_N_NEXT,.next_nodes =
- {
+ .vector_size = sizeof (u32),
+ .n_errors = TCP_N_ERROR,
+ .error_strings = tcp_error_strings,
+ .n_next_nodes = TCP_OUTPUT_N_NEXT,
+ .next_nodes = {
#define _(s,n) [TCP_OUTPUT_NEXT_##s] = n,
foreach_tcp4_output_next
#undef _
- }
-,.format_buffer = format_tcp_header,.format_trace = format_tcp_tx_trace,};
+ },
+ .format_buffer = format_tcp_header,
+ .format_trace = format_tcp_tx_trace,
+};
+/* *INDENT-ON* */
-VLIB_NODE_FUNCTION_MULTIARCH (tcp4_output_node, tcp4_output)
+VLIB_NODE_FUNCTION_MULTIARCH (tcp4_output_node, tcp4_output);
+
+/* *INDENT-OFF* */
VLIB_REGISTER_NODE (tcp6_output_node) =
{
- .function = tcp6_output,.name = "tcp6-output",
+ .function = tcp6_output,
+ .name = "tcp6-output",
/* Takes a vector of packets. */
- .vector_size = sizeof (u32),.n_errors = TCP_N_ERROR,.error_strings =
- tcp_error_strings,.n_next_nodes = TCP_OUTPUT_N_NEXT,.next_nodes =
- {
+ .vector_size = sizeof (u32),
+ .n_errors = TCP_N_ERROR,
+ .error_strings = tcp_error_strings,
+ .n_next_nodes = TCP_OUTPUT_N_NEXT,
+ .next_nodes = {
#define _(s,n) [TCP_OUTPUT_NEXT_##s] = n,
foreach_tcp6_output_next
#undef _
- }
-,.format_buffer = format_tcp_header,.format_trace = format_tcp_tx_trace,};
+ },
+ .format_buffer = format_tcp_header,
+ .format_trace = format_tcp_tx_trace,
+};
+/* *INDENT-ON* */
-VLIB_NODE_FUNCTION_MULTIARCH (tcp6_output_node, tcp6_output) u32
+VLIB_NODE_FUNCTION_MULTIARCH (tcp6_output_node, tcp6_output);
+
+u32
tcp_push_header (transport_connection_t * tconn, vlib_buffer_t * b)
{
tcp_connection_t *tc;
@@ -1405,7 +1403,7 @@
next0 = TCP_RESET_NEXT_IP_LOOKUP;
done:
- b0->error = error0 != 0 ? node->errors[error0] : 0;
+ b0->error = node->errors[error0];
b0->flags |= VNET_BUFFER_LOCALLY_ORIGINATED;
if (PREDICT_FALSE (b0->flags & VLIB_BUFFER_IS_TRACED))
{
@@ -1450,6 +1448,8 @@
};
/* *INDENT-ON* */
+VLIB_NODE_FUNCTION_MULTIARCH (tcp4_reset_node, tcp4_send_reset);
+
/* *INDENT-OFF* */
VLIB_REGISTER_NODE (tcp6_reset_node) = {
.function = tcp6_send_reset,
@@ -1466,6 +1466,8 @@
};
/* *INDENT-ON* */
+VLIB_NODE_FUNCTION_MULTIARCH (tcp6_reset_node, tcp6_send_reset);
+
/*
* fd.io coding-style-patch-verification: ON
*