Re: git: 00812bbda25a - main - bblog: add logging of protocol user requests

From: Konstantin Belousov <kostikbel_at_gmail.com>
Date: Tue, 21 Feb 2023 13:31:45 UTC
On Tue, Feb 21, 2023 at 11:11:51AM +0000, Michael Tuexen wrote:
> The branch main has been updated by tuexen:
> 
> URL: https://cgit.FreeBSD.org/src/commit/?id=00812bbda25a7a97008650dfbc20da43a9485f88
> 
> commit 00812bbda25a7a97008650dfbc20da43a9485f88
> Author:     Michael Tuexen <tuexen@FreeBSD.org>
> AuthorDate: 2023-02-21 11:07:35 +0000
> Commit:     Michael Tuexen <tuexen@FreeBSD.org>
> CommitDate: 2023-02-21 11:07:35 +0000
> 
>     bblog: add logging of protocol user requests
>     
>     This information was available in trpt and is useful. So provide
>     a way to get this information via TCP BBLog.
>     
>     Reviewed by:            rscheff@
>     Sponsored by:           Netflix, Inc.
>     Differential Revision:  https://reviews.freebsd.org/D38701
> ---
>  sys/netinet/tcp_log_buf.h |  3 ++-
>  sys/netinet/tcp_usrreq.c  | 37 +++++++++++++++++++++++++++++++++++++
>  2 files changed, 39 insertions(+), 1 deletion(-)
> 
> diff --git a/sys/netinet/tcp_log_buf.h b/sys/netinet/tcp_log_buf.h
> index 3c6569cffafd..f82d2bf3a9b3 100644
> --- a/sys/netinet/tcp_log_buf.h
> +++ b/sys/netinet/tcp_log_buf.h
> @@ -240,7 +240,8 @@ enum tcp_log_events {
>  	TCP_RACK_LOG_COLLAPSE,	/* Window collapse by peer 67 */
>  	TCP_RACK_TP_TRIGGERED,	/* A rack tracepoint is triggered 68 */
>  	TCP_HYBRID_PACING_LOG,	/* Hybrid pacing log 69 */
> -	TCP_LOG_END		/* End (keep at end)                70 */
> +	TCP_LOG_PRU,		/* TCP protocol user request        70 */
> +	TCP_LOG_END		/* End (keep at end)                71 */
>  };
>  
>  enum tcp_log_states {
> diff --git a/sys/netinet/tcp_usrreq.c b/sys/netinet/tcp_usrreq.c
> index 0c36e4281010..60bb59b64868 100644
> --- a/sys/netinet/tcp_usrreq.c
> +++ b/sys/netinet/tcp_usrreq.c
> @@ -131,6 +131,26 @@ static void	tcp_fill_info(struct tcpcb *, struct tcp_info *);
>  
>  static int	tcp_pru_options_support(struct tcpcb *tp, int flags);
>  
> +static void
> +tcp_bblog_pru(struct tcpcb *tp, uint32_t pru, int error)
> +{
> +	struct tcp_log_buffer *lgb;
> +
> +	INP_WLOCK_ASSERT(tptoinpcb(tp));
> +	if (tp->t_logstate != TCP_LOG_STATE_OFF) {
> +		lgb = tcp_log_event_(tp, NULL, NULL, NULL, TCP_LOG_PRU, error,
> +		    0, NULL, false, NULL, NULL, 0, NULL);
> +	} else {
> +		lgb = NULL;
> +	}
> +	if (lgb != NULL) {
> +		if (error >= 0) {
> +			lgb->tlb_errno = (uint32_t)error;
> +		}
> +		lgb->tlb_flex1 = pru;
> +	}
> +}
> +
>  /*
>   * TCP attaches to socket via pru_attach(), reserving space,
>   * and an internet control block.
> @@ -163,6 +183,7 @@ tcp_usr_attach(struct socket *so, int proto, struct thread *td)
>  		goto out;
>  	}
>  	tp->t_state = TCPS_CLOSED;
> +	tcp_bblog_pru(tp, PRU_ATTACH, error);
>  	INP_WUNLOCK(inp);
>  	TCPSTATES_INC(TCPS_CLOSED);
>  out:
> @@ -248,6 +269,7 @@ tcp_usr_bind(struct socket *so, struct sockaddr *nam, struct thread *td)
>  	error = in_pcbbind(inp, sinp, td->td_ucred);
>  	INP_HASH_WUNLOCK(&V_tcbinfo);
>  out:
> +	tcp_bblog_pru(tp, PRU_BIND, error);
>  	TCP_PROBE2(debug__user, tp, PRU_BIND);
>  	INP_WUNLOCK(inp);
>  
> @@ -320,6 +342,7 @@ tcp6_usr_bind(struct socket *so, struct sockaddr *nam, struct thread *td)
>  out:
>  	if (error != 0)
>  		inp->inp_vflag = vflagsav;
> +	tcp_bblog_pru(tp, PRU_BIND, error);
>  	TCP_PROBE2(debug__user, tp, PRU_BIND);
>  	INP_WUNLOCK(inp);
>  	return (error);
> @@ -372,6 +395,7 @@ tcp_usr_listen(struct socket *so, int backlog, struct thread *td)
>  		tp->t_tfo_pending = tcp_fastopen_alloc_counter();
>  
>  out:
> +	tcp_bblog_pru(tp, PRU_LISTEN, error);
>  	TCP_PROBE2(debug__user, tp, PRU_LISTEN);
>  	INP_WUNLOCK(inp);
>  	return (error);
> @@ -429,6 +453,7 @@ tcp6_usr_listen(struct socket *so, int backlog, struct thread *td)
>  		inp->inp_vflag = vflagsav;
>  
>  out:
> +	tcp_bblog_pru(tp, PRU_LISTEN, error);
>  	TCP_PROBE2(debug__user, tp, PRU_LISTEN);
>  	INP_WUNLOCK(inp);
>  	return (error);
> @@ -496,6 +521,7 @@ tcp_usr_connect(struct socket *so, struct sockaddr *nam, struct thread *td)
>  out_in_epoch:
>  	NET_EPOCH_EXIT(et);
>  out:
> +	tcp_bblog_pru(tp, PRU_CONNECT, error);
>  	TCP_PROBE2(debug__user, tp, PRU_CONNECT);
>  	INP_WUNLOCK(inp);
>  	return (error);
> @@ -620,6 +646,7 @@ out:
>  		inp->inp_inc.inc_flags = incflagsav;
>  	}
>  
> +	tcp_bblog_pru(tp, PRU_CONNECT, error);
>  	TCP_PROBE2(debug__user, tp, PRU_CONNECT);
>  	INP_WUNLOCK(inp);
>  	return (error);
> @@ -658,6 +685,7 @@ tcp_usr_disconnect(struct socket *so)
>  		goto out;
>  	tcp_disconnect(tp);
>  out:
> +	tcp_bblog_pru(tp, PRU_DISCONNECT, error);
>  	TCP_PROBE2(debug__user, tp, PRU_DISCONNECT);
>  	INP_WUNLOCK(inp);
>  	NET_EPOCH_EXIT(et);
> @@ -703,6 +731,7 @@ tcp_usr_accept(struct socket *so, struct sockaddr **nam)
>  	addr = inp->inp_faddr;
>  
>  out:
> +	tcp_bblog_pru(tp, PRU_ACCEPT, error);
>  	TCP_PROBE2(debug__user, tp, PRU_ACCEPT);
>  	INP_WUNLOCK(inp);
>  	if (error == 0)
> @@ -756,6 +785,7 @@ tcp6_usr_accept(struct socket *so, struct sockaddr **nam)
>  	}
>  
>  out:
> +	tcp_bblog_pru(tp, PRU_ACCEPT, error);
>  	TCP_PROBE2(debug__user, tp, PRU_ACCEPT);
>  	INP_WUNLOCK(inp);
>  	NET_EPOCH_EXIT(et);
> @@ -793,6 +823,7 @@ tcp_usr_shutdown(struct socket *so)
>  	tcp_usrclosed(tp);
>  	if (!(inp->inp_flags & INP_DROPPED))
>  		error = tcp_output_nodrop(tp);
> +	tcp_bblog_pru(tp, PRU_SHUTDOWN, error);
>  	TCP_PROBE2(debug__user, tp, PRU_SHUTDOWN);
>  	error = tcp_unlock_or_drop(tp, error);
>  	NET_EPOCH_EXIT(et);
> @@ -837,6 +868,7 @@ tcp_usr_rcvd(struct socket *so, int flags)
>  #endif
>  		outrv = tcp_output_nodrop(tp);
>  out:
> +	tcp_bblog_pru(tp, PRU_RCVD, error);
>  	TCP_PROBE2(debug__user, tp, PRU_RCVD);
>  	(void) tcp_unlock_or_drop(tp, outrv);
>  	NET_EPOCH_EXIT(et);
> @@ -1156,6 +1188,8 @@ out:
>  		inp->inp_vflag = vflagsav;
>  		inp->inp_inc.inc_flags = incflagsav;
>  	}
> +	tcp_bblog_pru(tp, (flags & PRUS_OOB) ? PRU_SENDOOB :
> +		      ((flags & PRUS_EOF) ? PRU_SEND_EOF : PRU_SEND), error);
>  	TCP_PROBE2(debug__user, tp, (flags & PRUS_OOB) ? PRU_SENDOOB :
>  		   ((flags & PRUS_EOF) ? PRU_SEND_EOF : PRU_SEND));
>  	error = tcp_unlock_or_drop(tp, error);
> @@ -1220,6 +1254,7 @@ tcp_usr_abort(struct socket *so)
>  		tp = tcp_drop(tp, ECONNABORTED);
>  		if (tp == NULL)
>  			goto dropped;
> +		tcp_bblog_pru(tp, PRU_ABORT, 0);
>  		TCP_PROBE2(debug__user, tp, PRU_ABORT);
>  	}
>  	if (!(inp->inp_flags & INP_DROPPED)) {
> @@ -1258,6 +1293,7 @@ tcp_usr_close(struct socket *so)
>  		if (tp->t_state != TCPS_TIME_WAIT) {
>  			tp->t_flags |= TF_CLOSED;
>  			tcp_disconnect(tp);
> +			tcp_bblog_pru(tp, PRU_CLOSE, 0);
>  			TCP_PROBE2(debug__user, tp, PRU_CLOSE);
>  		}
>  	}
> @@ -1326,6 +1362,7 @@ tcp_usr_rcvoob(struct socket *so, struct mbuf *m, int flags)
>  		tp->t_oobflags ^= (TCPOOB_HAVEDATA | TCPOOB_HADDATA);
>  
>  out:
> +	tcp_bblog_pru(tp, PRU_RCVOOB, error);
>  	TCP_PROBE2(debug__user, tp, PRU_RCVOOB);
>  	INP_WUNLOCK(inp);
>  	return (error);

I get
../../../netinet/tcp_usrreq.c:272:16: error: use of undeclared identifier 'tp'
        tcp_bblog_pru(tp, PRU_BIND, error);
                      ^
../../../netinet/tcp_usrreq.c:345:16: error: use of undeclared identifier 'tp'
        tcp_bblog_pru(tp, PRU_BIND, error);
                      ^
../../../netinet/tcp_usrreq.c:734:16: error: use of undeclared identifier 'tp'
        tcp_bblog_pru(tp, PRU_ACCEPT, error);
                      ^
../../../netinet/tcp_usrreq.c:788:16: error: use of undeclared identifier 'tp'
        tcp_bblog_pru(tp, PRU_ACCEPT, error);
                      ^
4 errors generated.
--- tcp_usrreq.o ---
*** [tcp_usrreq.o] Error code 1

Obviously, the KDTRACE_HOOKS option is not enabled in my kernel.