d/freebsd-skq
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

An important statistic in determining if a server process (or client) is being delayed

Browse Source 
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
This commit is contained in:
Randall Stewart 2020-06-08 11:48:07 +00:00
parent 7465a290a0
commit e854dd38ac
7 changed files with 74 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

18
sys/netinet/tcp_input.c
View File

@ -1841,6 +1841,15 @@ tcp_do_segment(struct mbuf *m, struct tcphdr *th, struct socket *so,
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 @@ tcp_do_segment(struct mbuf *m, struct tcphdr *th, struct socket *so,
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);

3
sys/netinet/tcp_log_buf.c
View File

@ -1693,6 +1693,9 @@ tcp_log_event_(struct tcpcb *tp, struct tcphdr *th, struct sockbuf *rxbuf,
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;

5
sys/netinet/tcp_log_buf.h
View File

@ -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 */

18
sys/netinet/tcp_stacks/bbr.c
View File

@ -8415,6 +8415,15 @@ bbr_process_data(struct mbuf *m, struct tcphdr *th, struct socket *so,
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, struct socket *so,
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.
*/

18
sys/netinet/tcp_stacks/rack.c
View File

@ -8763,6 +8763,15 @@ rack_process_data(struct mbuf *m, struct tcphdr *th, struct socket *so,
#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, struct socket *so,
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.
*/

10
sys/netinet/tcp_usrreq.c
View File

@ -1196,6 +1196,16 @@ tcp_usr_send(struct socket *so, int flags, struct mbuf *m,
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)

4
sys/netinet/tcp_var.h
View File

@ -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.