Improve session debugging
Also improves builtin client code.
Change-Id: I8bca1aa632028f95c373726efb0abf2ee0eff414
Signed-off-by: Florin Coras <fcoras@cisco.com>
diff --git a/src/svm/svm_fifo.c b/src/svm/svm_fifo.c
index 9b09d0c..f13f6fe 100644
--- a/src/svm/svm_fifo.c
+++ b/src/svm/svm_fifo.c
@@ -54,19 +54,20 @@
s = format (s, "cursize %u nitems %u has_event %d\n",
f->cursize, f->nitems, f->has_event);
- s = format (s, "head %d tail %d\n", f->head, f->tail);
+ s = format (s, " head %d tail %d\n", f->head, f->tail);
if (verbose > 1)
s = format
- (s, "server session %d thread %d client session %d thread %d\n",
+ (s, " server session %d thread %d client session %d thread %d\n",
f->master_session_index, f->master_thread_index,
f->client_session_index, f->client_thread_index);
if (verbose)
{
- s = format (s, "ooo pool %d active elts\n",
+ s = format (s, " ooo pool %d active elts\n",
pool_elts (f->ooo_segments));
- s = format (s, "%U", format_ooo_list, f);
+ if (svm_fifo_has_ooo_data (f))
+ s = format (s, " %U", format_ooo_list, f);
}
return s;
}
diff --git a/src/vnet/session/session_cli.c b/src/vnet/session/session_cli.c
index f5990c8..509eedb 100755
--- a/src/vnet/session/session_cli.c
+++ b/src/vnet/session/session_cli.c
@@ -30,33 +30,35 @@
int verbose = va_arg (*args, int);
transport_proto_vft_t *tp_vft;
u8 *str = 0;
-
tp_vft = session_get_transport_vft (ss->session_type);
- if (verbose)
- str = format (0, "%-20llp%-20llp%-15lld", ss->server_rx_fifo,
- ss->server_tx_fifo, stream_session_get_index (ss));
+ if (verbose == 1)
+ str = format (0, "%-10u%-10u%-10lld",
+ svm_fifo_max_dequeue (ss->server_rx_fifo),
+ svm_fifo_max_enqueue (ss->server_tx_fifo),
+ stream_session_get_index (ss));
if (ss->session_state == SESSION_STATE_READY)
{
- s = format (s, "%-40U%v", tp_vft->format_connection,
- ss->connection_index, ss->thread_index, str);
+ s = format (s, "%U", tp_vft->format_connection, ss->connection_index,
+ ss->thread_index, verbose);
+ if (verbose == 1)
+ s = format (s, "%v", str);
}
else if (ss->session_state == SESSION_STATE_LISTENING)
{
s = format (s, "%-40U%v", tp_vft->format_listener, ss->connection_index,
str);
}
- else if (ss->session_state == SESSION_STATE_READY)
+ else if (ss->session_state == SESSION_STATE_CONNECTING)
{
- s =
- format (s, "%-40U%v", tp_vft->format_half_open, ss->connection_index,
- str);
+ s = format (s, "%-40U%v", tp_vft->format_half_open,
+ ss->connection_index, str);
}
else if (ss->session_state == SESSION_STATE_CLOSED)
{
s = format (s, "[CL] %-40U%v", tp_vft->format_connection,
- ss->connection_index, ss->thread_index, str);
+ ss->connection_index, ss->thread_index, verbose, str);
}
else
{
@@ -85,7 +87,9 @@
while (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
{
- if (unformat (input, "verbose"))
+ if (unformat (input, "verbose %d", &verbose))
+ ;
+ else if (unformat (input, "verbose"))
verbose = 1;
else
break;
@@ -105,11 +109,11 @@
i, pool_elts (pool));
if (verbose)
{
- if (once_per_pool)
+ if (once_per_pool && verbose == 1)
{
- str = format (str, "%-50s%-20s%-20s%-15s",
- "Connection", "Rx fifo", "Tx fifo",
- "Session Index");
+ str =
+ format (str, "%-50s%-15s%-10s%-10s%-10s", "Connection",
+ "State", "Rx-f", "Tx-f", "S-idx");
vlib_cli_output (vm, "%v", str);
vec_reset_length (str);
once_per_pool = 0;
@@ -118,7 +122,16 @@
/* *INDENT-OFF* */
pool_foreach (s, pool,
({
- vlib_cli_output (vm, "%U", format_stream_session, s, verbose);
+ vec_reset_length (str);
+ str = format (str, "%U", format_stream_session, s, verbose);
+ if (verbose > 1)
+ {
+ str = format (str, " Rx fifo: %U", format_svm_fifo,
+ s->server_rx_fifo, 1);
+ str = format (str, " Tx fifo: %U", format_svm_fifo,
+ s->server_tx_fifo, 1);
+ }
+ vlib_cli_output (vm, "%v", str);
}));
/* *INDENT-ON* */
}
diff --git a/src/vnet/tcp/builtin_client.c b/src/vnet/tcp/builtin_client.c
index d13fd44..aaefa7e 100644
--- a/src/vnet/tcp/builtin_client.c
+++ b/src/vnet/tcp/builtin_client.c
@@ -187,6 +187,9 @@
clib_per_cpu_mheaps[vlib_get_thread_index ()] = clib_per_cpu_mheaps[0];
+ vec_validate (session_indices, 0);
+ vec_reset_length (session_indices);
+
while (1)
{
/* Wait until we're told to get busy */
@@ -201,14 +204,12 @@
tm->run_test = 0;
rx_total = 0;
- clib_warning ("Run %d iterations", tm->n_iterations);
+ clib_warning ("Start test...");
before = clib_time_now (&ttime);
- for (i = 0; i < tm->n_iterations; i++)
+ do
{
- session_t *sp;
-
do
{
try_tx = try_rx = 0;
@@ -229,24 +230,38 @@
receive_test_chunk (tm, sp);
try_rx = 1;
}
+ else
+ {
+ /* Session is complete */
+ vec_add1 (session_indices, sp - tm->sessions);
+ }
}));
+ /* Terminate any completed sessions */
+ if (PREDICT_FALSE (_vec_len(session_indices) != 0))
+ {
+ for (i = 0; i < _vec_len (session_indices); i++)
+ {
+ sp = pool_elt_at_index (tm->sessions, session_indices[i]);
+ rx_total += sp->bytes_received;
+ dmp = vl_msg_api_alloc_as_if_client (sizeof (*dmp));
+ memset (dmp, 0, sizeof (*dmp));
+ dmp->_vl_msg_id = ntohs (VL_API_DISCONNECT_SESSION);
+ dmp->client_index = tm->my_client_index;
+ dmp->handle = sp->vpp_session_handle;
+ vl_msg_api_send_shmem (tm->vl_input_queue, (u8 *) & dmp);
+ pool_put (tm->sessions, sp);
+ }
+ _vec_len(session_indices) = 0;
+ }
/* *INDENT-ON* */
}
while (try_tx || try_rx);
-
- /* *INDENT-OFF* */
- pool_foreach (sp, tm->sessions,
- ({
- rx_total += sp->bytes_received;
- sp->bytes_received = 0;
- sp->bytes_to_send = tm->bytes_to_send;
- }));
- /* *INDENT-ON* */
}
+ while (0);
after = clib_time_now (&ttime);
- clib_warning ("Done %d iterations, %lld bytes in %.2f secs",
- tm->n_iterations, rx_total, (after - before));
+ clib_warning ("Test complete %lld bytes in %.2f secs",
+ rx_total, (after - before));
if ((after - before) != 0.0)
{
clib_warning ("%.2f bytes/second full-duplex",
@@ -255,28 +270,11 @@
(((f64) rx_total * 8.0) / (after - before)) / 1e9);
}
- /* Disconnect sessions... */
- vec_reset_length (session_indices);
-
- /* *INDENT-OFF* */
- pool_foreach (sp, tm->sessions,
- ({
- vec_add1 (session_indices, sp - tm->sessions);
- }));
- /* *INDENT-ON* */
-
- for (i = 0; i < vec_len (session_indices); i++)
- {
- sp = pool_elt_at_index (tm->sessions, session_indices[i]);
- dmp = vl_msg_api_alloc_as_if_client (sizeof (*dmp));
- memset (dmp, 0, sizeof (*dmp));
- dmp->_vl_msg_id = ntohs (VL_API_DISCONNECT_SESSION);
- dmp->client_index = tm->my_client_index;
- dmp->handle = sp->vpp_session_handle;
- vl_msg_api_send_shmem (tm->vl_input_queue, (u8 *) & dmp);
- pool_put (tm->sessions, sp);
- }
+ if (pool_elts (tm->sessions))
+ clib_warning ("BUG: %d active sessions remain...",
+ pool_elts (tm->sessions));
}
+ while (0);
/* NOTREACHED */
#if TCP_BUILTIN_CLIENT_PTHREAD
return 0;
@@ -511,15 +509,12 @@
u64 tmp;
tm->bytes_to_send = 8192;
- tm->n_iterations = 1;
vec_free (tm->connect_uri);
while (unformat_check_input (input) != UNFORMAT_END_OF_INPUT)
{
if (unformat (input, "nclients %d", &n_clients))
;
- else if (unformat (input, "iterations %d", &tm->n_iterations))
- ;
else if (unformat (input, "mbytes %lld", &tmp))
tm->bytes_to_send = tmp << 20;
else if (unformat (input, "gbytes %lld", &tmp))
diff --git a/src/vnet/tcp/builtin_client.h b/src/vnet/tcp/builtin_client.h
index 756b3d1..57d112e 100644
--- a/src/vnet/tcp/builtin_client.h
+++ b/src/vnet/tcp/builtin_client.h
@@ -93,9 +93,6 @@
/* Signal variables */
volatile int run_test;
- /* Number of iterations */
- int n_iterations;
-
/* Bytes to send */
u64 bytes_to_send;
diff --git a/src/vnet/tcp/tcp.c b/src/vnet/tcp/tcp.c
index 36d85e4..9b7b2f6 100644
--- a/src/vnet/tcp/tcp.c
+++ b/src/vnet/tcp/tcp.c
@@ -461,13 +461,12 @@
u8 *
format_tcp_state (u8 * s, va_list * args)
{
- tcp_state_t *state = va_arg (*args, tcp_state_t *);
+ u32 state = va_arg (*args, u32);
- if (*state < TCP_N_STATES)
- s = format (s, "%s", tcp_fsm_states[*state]);
+ if (state < TCP_N_STATES)
+ s = format (s, "%s", tcp_fsm_states[state]);
else
- s = format (s, "UNKNOWN (%d (0x%x))", *state, *state);
-
+ s = format (s, "UNKNOWN (%d (0x%x))", state, state);
return s;
}
@@ -503,7 +502,51 @@
}
u8 *
-format_tcp_connection (u8 * s, va_list * args)
+format_tcp_congestion_status (u8 * s, va_list * args)
+{
+ tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+ if (tcp_in_recovery (tc))
+ s = format (s, "recovery");
+ else if (tcp_in_fastrecovery (tc))
+ s = format (s, "fastrecovery");
+ else
+ s = format (s, "none");
+ return s;
+}
+
+u8 *
+format_tcp_vars (u8 * s, va_list * args)
+{
+ tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
+ s = format (s, " snd_una %u snd_nxt %u snd_una_max %u\n",
+ tc->snd_una - tc->iss, tc->snd_nxt - tc->iss,
+ tc->snd_una_max - tc->iss);
+ s = format (s, " rcv_nxt %u rcv_las %u\n",
+ tc->rcv_nxt - tc->irs, tc->rcv_las - tc->irs);
+ s = format (s, " snd_wnd %u rcv_wnd %u snd_wl1 %u snd_wl2 %u\n",
+ tc->snd_wnd, tc->rcv_wnd, tc->snd_wl1 - tc->irs,
+ tc->snd_wl2 - tc->iss);
+ s = format (s, " flight size %u send space %u rcv_wnd available %d\n",
+ tcp_flight_size (tc), tcp_snd_space (tc),
+ tc->rcv_wnd - (tc->rcv_nxt - tc->rcv_las));
+ s = format (s, " cong %U ", format_tcp_congestion_status, tc);
+ s = format (s, "cwnd %u ssthresh %u rtx_bytes %u bytes_acked %u\n",
+ tc->cwnd, tc->ssthresh, tc->rtx_bytes, tc->bytes_acked);
+ s = format (s, " prev_ssthresh %u snd_congestion %u\n", tc->prev_ssthresh,
+ tc->snd_congestion - tc->iss);
+ s = format (s, " rto %u rto_boff %u srtt %u rttvar %u rtt_ts %u ", tc->rto,
+ tc->rto_boff, tc->srtt, tc->rttvar, tc->rtt_ts);
+ s = format (s, "rtt_seq %u\n", tc->rtt_seq);
+ if (scoreboard_first_hole (&tc->sack_sb))
+ s = format (s, " scoreboard: %U\n", format_tcp_scoreboard, &tc->sack_sb);
+ if (vec_len (tc->snd_sacks))
+ s = format (s, " sacks tx: %U\n", format_tcp_sacks, tc);
+
+ return s;
+}
+
+u8 *
+format_tcp_connection_id (u8 * s, va_list * args)
{
tcp_connection_t *tc = va_arg (*args, tcp_connection_t *);
if (!tc)
@@ -527,11 +570,18 @@
}
u8 *
-format_tcp_connection_verbose (u8 * s, va_list * args)
+format_tcp_connection (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);
+ u32 verbose = va_arg (*args, u32);
+
+ s = format (s, "%-50U", format_tcp_connection_id, tc);
+ if (verbose)
+ {
+ s = format (s, "%-15U", format_tcp_state, tc->state);
+ if (verbose > 1)
+ s = format (s, " %U\n%U", format_tcp_timers, tc, format_tcp_vars, tc);
+ }
return s;
}
@@ -540,11 +590,12 @@
{
u32 tci = va_arg (*args, u32);
u32 thread_index = va_arg (*args, u32);
+ u32 verbose = va_arg (*args, u32);
tcp_connection_t *tc;
tc = tcp_connection_get (tci, thread_index);
if (tc)
- return format (s, "%U", format_tcp_connection, tc);
+ return format (s, "%U", format_tcp_connection, tc, verbose);
else
return format (s, "empty");
}
@@ -554,7 +605,7 @@
{
u32 tci = va_arg (*args, u32);
tcp_connection_t *tc = tcp_listener_get (tci);
- return format (s, "%U", format_tcp_connection, tc);
+ return format (s, "%U", format_tcp_connection_id, tc);
}
u8 *
@@ -562,7 +613,7 @@
{
u32 tci = va_arg (*args, u32);
tcp_connection_t *tc = tcp_half_open_connection_get (tci);
- return format (s, "%U", format_tcp_connection, tc);
+ return format (s, "%U", format_tcp_connection_id, tc);
}
u8 *
@@ -659,12 +710,18 @@
/**
* Compute tx window session is allowed to fill.
+ *
+ * Takes into account available send space, snd_mss and the congestion
+ * state of the connection. If possible, the value returned is a multiple
+ * of snd_mss.
+ *
+ * @param tc tcp connection
+ * @return number of bytes session is allowed to write
*/
u32
-tcp_session_send_space (transport_connection_t * trans_conn)
+tcp_snd_space (tcp_connection_t * tc)
{
int snd_space;
- tcp_connection_t *tc = (tcp_connection_t *) trans_conn;
/* If we haven't gotten dupacks or if we did and have gotten sacked bytes
* then we can still send */
@@ -698,6 +755,13 @@
}
u32
+tcp_session_send_space (transport_connection_t * trans_conn)
+{
+ tcp_connection_t *tc = (tcp_connection_t *) trans_conn;
+ return tcp_snd_space (tc);
+}
+
+u32
tcp_session_tx_fifo_offset (transport_connection_t * trans_conn)
{
tcp_connection_t *tc = (tcp_connection_t *) trans_conn;
diff --git a/src/vnet/tcp/tcp.h b/src/vnet/tcp/tcp.h
index 8d24a70..c3ebe22 100644
--- a/src/vnet/tcp/tcp.h
+++ b/src/vnet/tcp/tcp.h
@@ -387,8 +387,8 @@
void tcp_connection_del (tcp_connection_t * tc);
void tcp_connection_reset (tcp_connection_t * tc);
+u8 *format_tcp_connection_id (u8 * s, va_list * args);
u8 *format_tcp_connection (u8 * s, va_list * args);
-u8 *format_tcp_connection_verbose (u8 * s, va_list * args);
u8 *format_tcp_scoreboard (u8 * s, va_list * args);
always_inline tcp_connection_t *
@@ -481,6 +481,8 @@
return available_wnd - flight_size;
}
+u32 tcp_rcv_wnd_available (tcp_connection_t * tc);
+u32 tcp_snd_space (tcp_connection_t * tc);
void tcp_update_rcv_wnd (tcp_connection_t * tc);
void tcp_retransmit_first_unacked (tcp_connection_t * tc);
diff --git a/src/vnet/tcp/tcp_input.c b/src/vnet/tcp/tcp_input.c
index 9d3f4cc..35bc909 100644
--- a/src/vnet/tcp/tcp_input.c
+++ b/src/vnet/tcp/tcp_input.c
@@ -722,9 +722,11 @@
TCP_EVT_DBG (TCP_EVT_SND_WND, tc);
/* Set probe timer if we just got 0 wnd */
- if (tc->snd_wnd < tc->snd_mss
- && !tcp_timer_is_active (tc, TCP_TIMER_PERSIST))
- tcp_persist_timer_set (tc);
+ if (tc->snd_wnd < tc->snd_mss)
+ {
+ if (!tcp_timer_is_active (tc, TCP_TIMER_PERSIST))
+ tcp_persist_timer_set (tc);
+ }
else
tcp_persist_timer_reset (tc);
}
@@ -763,6 +765,7 @@
tcp_cc_rcv_ack (tcp_connection_t * tc, vlib_buffer_t * b)
{
u8 partial_ack;
+ u32 bytes_advanced;
if (tcp_in_fastrecovery (tc))
{
@@ -804,10 +807,14 @@
tc->rcv_dupacks = 0;
if (tcp_in_recovery (tc))
{
- tc->rtx_bytes -= clib_min (tc->bytes_acked, tc->rtx_bytes);
+ bytes_advanced = tc->bytes_acked + tc->sack_sb.snd_una_adv;
+ tc->rtx_bytes -= clib_min (bytes_advanced, tc->rtx_bytes);
tc->rto = clib_min (tc->srtt + (tc->rttvar << 2), TCP_RTO_MAX);
if (seq_geq (tc->snd_una, tc->snd_congestion))
- tcp_recovery_off (tc);
+ {
+ tc->rtx_bytes = 0;
+ tcp_recovery_off (tc);
+ }
}
}
}
@@ -1221,7 +1228,7 @@
s = format (s, "%U\n%U%U",
format_tcp_header, &t->tcp_header, 128,
format_white_space, indent,
- format_tcp_connection_verbose, &t->tcp_connection);
+ format_tcp_connection, &t->tcp_connection, 1);
return s;
}
@@ -1236,7 +1243,7 @@
s = format (s, "%d -> %d (%U)",
clib_net_to_host_u16 (t->tcp_header.src_port),
clib_net_to_host_u16 (t->tcp_header.dst_port), format_tcp_state,
- &t->tcp_connection.state);
+ t->tcp_connection.state);
return s;
}
@@ -2165,6 +2172,7 @@
child0->c_rmt_port = th0->src_port;
child0->c_is_ip4 = is_ip4;
child0->c_thread_index = my_thread_index;
+ child0->state = TCP_STATE_SYN_RCVD;
if (is_ip4)
{
@@ -2194,7 +2202,6 @@
child0->irs = vnet_buffer (b0)->tcp.seq_number;
child0->rcv_nxt = vnet_buffer (b0)->tcp.seq_number + 1;
child0->rcv_las = child0->rcv_nxt;
- child0->state = TCP_STATE_SYN_RCVD;
/* RFC1323: TSval timestamps sent on {SYN} and {SYN,ACK}
* segments are used to initialize PAWS. */
@@ -2450,7 +2457,7 @@
if (error0 == TCP_ERROR_DISPATCH)
clib_warning ("disp error state %U flags %U",
- format_tcp_state, &state0, format_tcp_flags,
+ format_tcp_state, state0, format_tcp_flags,
(int) flags0);
}
}
diff --git a/src/vnet/tcp/tcp_output.c b/src/vnet/tcp/tcp_output.c
index a462d8d..49fd6be 100644
--- a/src/vnet/tcp/tcp_output.c
+++ b/src/vnet/tcp/tcp_output.c
@@ -59,7 +59,7 @@
s = format (s, "%U\n%U%U",
format_tcp_header, &t->tcp_header, 128,
format_white_space, indent,
- format_tcp_connection_verbose, &t->tcp_connection);
+ format_tcp_connection, &t->tcp_connection, 1);
return s;
}
@@ -1024,6 +1024,11 @@
ASSERT (n_bytes != 0);
b->current_length = n_bytes;
tcp_push_hdr_i (tc, b, tc->state, 0);
+
+ /* Don't count multiple retransmits of the same segment */
+ if (tc->rto_boff > 1)
+ goto done;
+
tc->rtx_bytes += n_bytes;
done:
@@ -1103,7 +1108,9 @@
if (n_bytes == 0)
{
- clib_warning ("could not retransmit");
+ clib_warning ("could not retransmit anything");
+ /* Try again eventually */
+ tcp_retransmit_timer_set (tc);
return;
}
}
@@ -1203,6 +1210,7 @@
/* Nothing to send */
if (n_bytes == 0)
{
+ clib_warning ("persist found nothing to send");
tcp_return_buffer (tm);
return;
}