svn commit: r361926 - in head/sys/netinet: . tcp_stacks
Randall Stewart
rrs at FreeBSD.org
Mon Jun 8 11:48:09 UTC 2020
Author: rrs
Date: Mon Jun 8 11:48:07 2020
New Revision: 361926
URL: https://svnweb.freebsd.org/changeset/base/361926
Log:
An important statistic in determining if a server process (or client) is being delayed
is to know the time to first byte in and time to first byte out. Currently we
have no way to know these all we have is t_starttime. That (t_starttime) tells us
what time the 3 way handshake completed. We don't know when the first
request came in or how quickly we responded. Nor from a client perspective
do we know how long from when we sent out the first byte before the
server responded.
This small change adds the ability to track the TTFB's. This will show up in
BB logging which then can be pulled for later analysis. Note that currently
the tracking is via the ticks variable of all three variables. This provides
a very rough estimate (hz=1000 its 1ms). A follow-on set of work will be
to change all three of these values into something with a much finer resolution
(either microseconds or nanoseconds), though we may want to make the resolution
configurable so that on lower powered machines we could still use the much
cheaper ticks variable.
Sponsored by: Netflix Inc.
Differential Revision: https://reviews.freebsd.org/D24902
Modified:
head/sys/netinet/tcp_input.c
head/sys/netinet/tcp_log_buf.c
head/sys/netinet/tcp_log_buf.h
head/sys/netinet/tcp_stacks/bbr.c
head/sys/netinet/tcp_stacks/rack.c
head/sys/netinet/tcp_usrreq.c
head/sys/netinet/tcp_var.h
Modified: head/sys/netinet/tcp_input.c
==============================================================================
--- head/sys/netinet/tcp_input.c Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_input.c Mon Jun 8 11:48:07 2020 (r361926)
@@ -1841,6 +1841,15 @@ tcp_do_segment(struct mbuf *m, struct tcphdr *th, stru
tcp_clean_sackreport(tp);
TCPSTAT_INC(tcps_preddat);
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
/*
* Pull snd_wl1 up to prevent seq wrap relative to
* th_seq.
@@ -3016,6 +3025,15 @@ dodata: /* XXX */
else
tp->t_flags |= TF_ACKNOW;
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
thflags = th->th_flags & TH_FIN;
TCPSTAT_INC(tcps_rcvpack);
TCPSTAT_ADD(tcps_rcvbyte, tlen);
Modified: head/sys/netinet/tcp_log_buf.c
==============================================================================
--- head/sys/netinet/tcp_log_buf.c Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_log_buf.c Mon Jun 8 11:48:07 2020 (r361926)
@@ -1693,6 +1693,9 @@ retry:
COPY_STAT(snd_numholes);
COPY_STAT(snd_scale);
COPY_STAT(rcv_scale);
+ COPY_STAT_T(flags2);
+ COPY_STAT_T(fbyte_in);
+ COPY_STAT_T(fbyte_out);
#undef COPY_STAT
#undef COPY_STAT_T
log_buf->tlb_flex1 = 0;
Modified: head/sys/netinet/tcp_log_buf.h
==============================================================================
--- head/sys/netinet/tcp_log_buf.h Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_log_buf.h Mon Jun 8 11:48:07 2020 (r361926)
@@ -32,7 +32,7 @@
#define TCP_LOG_REASON_LEN 32
#define TCP_LOG_TAG_LEN 32
-#define TCP_LOG_BUF_VER (8)
+#define TCP_LOG_BUF_VER (9)
/*
* Because the (struct tcp_log_buffer) includes 8-byte uint64_t's, it requires
@@ -143,6 +143,7 @@ struct tcp_log_buffer
uint32_t tlb_rttvar; /* TCPCB t_rttvar */
uint32_t tlb_rcv_up; /* TCPCB rcv_up */
uint32_t tlb_rcv_adv; /* TCPCB rcv_adv */
+ uint32_t tlb_flags2; /* TCPCB t_flags2 */
uint32_t tlb_rcv_nxt; /* TCPCB rcv_nxt */
uint32_t tlb_rcv_wnd; /* TCPCB rcv_wnd */
uint32_t tlb_dupacks; /* TCPCB t_dupacks */
@@ -150,6 +151,8 @@ struct tcp_log_buffer
int tlb_snd_numholes; /* TCPCB snd_numholes */
uint32_t tlb_flex1; /* Event specific information */
uint32_t tlb_flex2; /* Event specific information */
+ uint32_t tlb_fbyte_in; /* TCPCB first byte in time */
+ uint32_t tlb_fbyte_out; /* TCPCB first byte out time */
uint8_t tlb_snd_scale:4, /* TCPCB snd_scale */
tlb_rcv_scale:4; /* TCPCB rcv_scale */
uint8_t _pad[3]; /* Padding */
Modified: head/sys/netinet/tcp_stacks/bbr.c
==============================================================================
--- head/sys/netinet/tcp_stacks/bbr.c Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_stacks/bbr.c Mon Jun 8 11:48:07 2020 (r361926)
@@ -8415,6 +8415,15 @@ bbr_process_data(struct mbuf *m, struct tcphdr *th, st
tp->t_flags |= TF_ACKNOW;
}
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
thflags = th->th_flags & TH_FIN;
KMOD_TCPSTAT_ADD(tcps_rcvpack, (int)nsegs);
KMOD_TCPSTAT_ADD(tcps_rcvbyte, tlen);
@@ -8631,6 +8640,15 @@ bbr_do_fastnewdata(struct mbuf *m, struct tcphdr *th,
tcp_clean_sackreport(tp);
KMOD_TCPSTAT_INC(tcps_preddat);
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
/*
* Pull snd_wl1 up to prevent seq wrap relative to th_seq.
*/
Modified: head/sys/netinet/tcp_stacks/rack.c
==============================================================================
--- head/sys/netinet/tcp_stacks/rack.c Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_stacks/rack.c Mon Jun 8 11:48:07 2020 (r361926)
@@ -8763,6 +8763,15 @@ rack_process_data(struct mbuf *m, struct tcphdr *th, s
#endif
rack_handle_delayed_ack(tp, rack, tlen, tfo_syn);
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
thflags = th->th_flags & TH_FIN;
KMOD_TCPSTAT_ADD(tcps_rcvpack, nsegs);
KMOD_TCPSTAT_ADD(tcps_rcvbyte, tlen);
@@ -8986,6 +8995,15 @@ rack_do_fastnewdata(struct mbuf *m, struct tcphdr *th,
tcp_clean_sackreport(tp);
KMOD_TCPSTAT_INC(tcps_preddat);
tp->rcv_nxt += tlen;
+ if (tlen &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_in == 0)) {
+ tp->t_fbyte_in = ticks;
+ if (tp->t_fbyte_in == 0)
+ tp->t_fbyte_in = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
/*
* Pull snd_wl1 up to prevent seq wrap relative to th_seq.
*/
Modified: head/sys/netinet/tcp_usrreq.c
==============================================================================
--- head/sys/netinet/tcp_usrreq.c Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_usrreq.c Mon Jun 8 11:48:07 2020 (r361926)
@@ -1196,6 +1196,16 @@ tcp_usr_send(struct socket *so, int flags, struct mbuf
socantsendmore(so);
tcp_usrclosed(tp);
}
+ if (TCPS_HAVEESTABLISHED(tp->t_state) &&
+ ((tp->t_flags2 & TF2_FBYTES_COMPLETE) == 0) &&
+ (tp->t_fbyte_out == 0) &&
+ (so->so_snd.sb_ccc > 0)) {
+ tp->t_fbyte_out = ticks;
+ if (tp->t_fbyte_out == 0)
+ tp->t_fbyte_out = 1;
+ if (tp->t_fbyte_out && tp->t_fbyte_in)
+ tp->t_flags2 |= TF2_FBYTES_COMPLETE;
+ }
if (!(inp->inp_flags & INP_DROPPED) &&
!(flags & PRUS_NOTREADY)) {
if (flags & PRUS_MORETOCOME)
Modified: head/sys/netinet/tcp_var.h
==============================================================================
--- head/sys/netinet/tcp_var.h Mon Jun 8 09:39:48 2020 (r361925)
+++ head/sys/netinet/tcp_var.h Mon Jun 8 11:48:07 2020 (r361926)
@@ -202,6 +202,8 @@ struct tcpcb {
tcp_seq t_rtseq; /* sequence number being timed */
u_int t_starttime; /* time connection was established */
+ u_int t_fbyte_in; /* ticks time when first byte queued in */
+ u_int t_fbyte_out; /* ticks time when first byte queued out */
u_int t_pmtud_saved_maxseg; /* pre-blackhole MSS */
int t_blackhole_enter; /* when to enter blackhole detection */
@@ -434,7 +436,7 @@ TAILQ_HEAD(tcp_funchead, tcp_function);
#define TF2_ECN_SND_CWR 0x00000040 /* ECN CWR in queue */
#define TF2_ECN_SND_ECE 0x00000080 /* ECN ECE in queue */
#define TF2_ACE_PERMIT 0x00000100 /* Accurate ECN mode */
-
+#define TF2_FBYTES_COMPLETE 0x00000400 /* We have first bytes in and out */
/*
* Structure to hold TCP options that are only used during segment
* processing (in tcp_input), but not held in the tcpcb.
More information about the svn-src-head
mailing list