From: Michael Tuexen <tuexen@FreeBSD.org> To: src-committers@FreeBSD.org, dev-commits-src-all@FreeBSD.org, dev-commits-src-main@FreeBSD.org Subject: git: a62c6b0de48a - main - ddb: add optional printing of BBLog entries
| raw e-mail | index | archive | help
The branch main has been updated by tuexen: URL: https://cgit.FreeBSD.org/src/commit/?id=a62c6b0de48a5b9b752976b2675ac807684b7fdb commit a62c6b0de48a5b9b752976b2675ac807684b7fdb Author: Michael Tuexen <tuexen@FreeBSD.org> AuthorDate: 2025-06-10 13:29:26 +0000 Commit: Michael Tuexen <tuexen@FreeBSD.org> CommitDate: 2025-06-10 13:29:26 +0000 ddb: add optional printing of BBLog entries Add a /b option to show tcpcb and show all tcpcbs to print BBLog entries. Right now this supports the entries generated by the FreeBSD default TCP stack. It should help in debugging issues reported by syzkaller. The syntax for printing sent and received packets is similar to the one used by packetdrill, since the output of ddb will be used to create packetdrill scripts for debugging. Reviewed by: thj Tested by: thj MFC after: 1 week Sponsored by: Netflix, Inc. Differential Revision: https://reviews.freebsd.org/D50629 --- share/man/man4/ddb.4 | 12 +- sys/netinet/tcp_log_buf.c | 381 ++++++++++++++++++++++++++++++++++++++++++++++ sys/netinet/tcp_log_buf.h | 4 + sys/netinet/tcp_usrreq.c | 15 +- 4 files changed, 405 insertions(+), 7 deletions(-) diff --git a/share/man/man4/ddb.4 b/share/man/man4/ddb.4 index 9a9af553b29d..3c4894c03d62 100644 --- a/share/man/man4/ddb.4 +++ b/share/man/man4/ddb.4 @@ -24,7 +24,7 @@ .\" any improvements or extensions that they make and grant Carnegie Mellon .\" the rights to redistribute these changes. .\" -.Dd May 28, 2025 +.Dd June 10, 2025 .Dt DDB 4 .Os .Sh NAME @@ -604,9 +604,12 @@ The modifier will print command line arguments for each process. .\" .Pp -.It Ic show Cm all tcpcbs Ns Op Li / Ns Cm l +.It Ic show Cm all tcpcbs Ns Op Li / Ns Cm b Ns Cm l Show the same output as "show tcpcb" does, but for all TCP control blocks within the system. +The +.Cm b +modifier will request BBLog entries to be printed. Using the .Cm l modifier will limit the output to TCP control blocks, which are locked. @@ -1103,7 +1106,7 @@ on i386.) Not present on some platforms. .\" .Pp -.It Ic show Cm tcpcb Ar addr +.It Ic show Cm tcpcb Ns Oo Li / Ns Cm b Oc Ar addr Print TCP control block .Vt struct tcpcb lying at address @@ -1111,6 +1114,9 @@ lying at address For exact interpretation of output, visit .Pa netinet/tcp.h header file. +The +.Cm b +modifier will request BBLog entries to be printed. .\" .Pp .It Ic show Cm thread Op Ar addr | tid diff --git a/sys/netinet/tcp_log_buf.c b/sys/netinet/tcp_log_buf.c index f540c7d3e70e..3c62d3b07f99 100644 --- a/sys/netinet/tcp_log_buf.c +++ b/sys/netinet/tcp_log_buf.c @@ -29,6 +29,7 @@ #include <sys/cdefs.h> #include "opt_inet.h" +#include "opt_ddb.h" #include <sys/param.h> #include <sys/arb.h> #include <sys/hash.h> @@ -43,11 +44,18 @@ #include <sys/socket.h> #include <sys/socketvar.h> #include <sys/sysctl.h> +#ifdef DDB +#include <sys/time.h> +#endif #include <sys/tree.h> #include <sys/stats.h> /* Must come after qmath.h and tree.h */ #include <sys/counter.h> #include <dev/tcp_log/tcp_log_dev.h> +#ifdef DDB +#include <ddb/ddb.h> +#endif + #include <net/if.h> #include <net/if_var.h> #include <net/vnet.h> @@ -2972,3 +2980,376 @@ skip_closed_req: done: INP_WUNLOCK(inp); } + +#ifdef DDB +static void +db_print_indent(int indent) +{ + int i; + + for (i = 0; i < indent; i++) + db_printf(" "); +} + +static void +db_print_tcphdr(struct tcp_log_buffer *tlm_buf) +{ + struct sackblk sack; + struct tcphdr *th; + int cnt, i, j, opt, optlen, num_sacks; + uint32_t val, ecr; + uint16_t mss; + uint16_t flags; + + if ((tlm_buf->tlb_eventflags & TLB_FLAG_HDR) == 0) { + return; + } + th = &tlm_buf->tlb_th; + flags = tcp_get_flags(th); + if (flags & TH_FIN) { + db_printf("F"); + } + if (flags & TH_SYN) { + db_printf("S"); + } + if (flags & TH_RST) { + db_printf("R"); + } + if (flags & TH_PUSH) { + db_printf("P"); + } + if (flags & TH_ACK) { + db_printf("."); + } + if (flags & TH_URG) { + db_printf("U"); + } + if (flags & TH_ECE) { + db_printf("E"); + } + if (flags & TH_FIN) { + db_printf("F"); + } + if (flags & TH_CWR) { + db_printf("W"); + } + if (flags & TH_FIN) { + db_printf("F"); + } + if (flags & TH_AE) { + db_printf("A"); + } + db_printf(" %u:%u(%u)", ntohl(th->th_seq), + ntohl(th->th_seq) + tlm_buf->tlb_len, tlm_buf->tlb_len); + if (flags & TH_ACK) { + db_printf(" ack %u", ntohl(th->th_ack)); + } + db_printf(" win %u", ntohs(th->th_win)); + if (flags & TH_URG) { + db_printf(" urg %u", ntohs(th->th_urp)); + } + cnt = (th->th_off << 2) - sizeof(struct tcphdr); + if (cnt > 0) { + db_printf(" <"); + for (i = 0; i < cnt; i += optlen) { + opt = tlm_buf->tlb_opts[i]; + if (opt == TCPOPT_EOL || opt == TCPOPT_NOP) { + optlen = 1; + } else { + if (cnt - i < 2) { + break; + } + optlen = tlm_buf->tlb_opts[i + 1]; + if (optlen < 2 || optlen > cnt - i) { + break; + } + } + if (i > 0) { + db_printf(","); + } + switch (opt) { + case TCPOPT_EOL: + db_printf("eol"); + break; + case TCPOPT_NOP: + db_printf("nop"); + break; + case TCPOPT_MAXSEG: + if (optlen != TCPOLEN_MAXSEG) { + break; + } + bcopy(tlm_buf->tlb_opts + i + 2, &mss, + sizeof(uint16_t)); + db_printf("mss %u", ntohs(mss)); + break; + case TCPOPT_WINDOW: + if (optlen != TCPOLEN_WINDOW) { + break; + } + db_printf("wscale %u", + tlm_buf->tlb_opts[i + 2]); + break; + case TCPOPT_SACK_PERMITTED: + if (optlen != TCPOLEN_SACK_PERMITTED) { + break; + } + db_printf("sackOK"); + break; + case TCPOPT_SACK: + if (optlen == TCPOLEN_SACKHDR || + (optlen - 2) % TCPOLEN_SACK != 0) { + break; + } + num_sacks = (optlen - 2) / TCPOLEN_SACK; + db_printf("sack"); + for (j = 0; j < num_sacks; j++) { + bcopy(tlm_buf->tlb_opts + i + 2 + + j * TCPOLEN_SACK, &sack, + TCPOLEN_SACK); + db_printf(" %u:%u", ntohl(sack.start), + ntohl(sack.end)); + } + break; + case TCPOPT_TIMESTAMP: + if (optlen != TCPOLEN_TIMESTAMP) { + break; + } + bcopy(tlm_buf->tlb_opts + i + 2, &val, + sizeof(uint32_t)); + bcopy(tlm_buf->tlb_opts + i + 6, &ecr, + sizeof(uint32_t)); + db_printf("TS val %u ecr %u", ntohl(val), + ntohl(ecr)); + break; + case TCPOPT_SIGNATURE: + db_printf("md5"); + if (optlen > 2) { + db_printf(" "); + } + for (j = 0; j < optlen - 2; j++) { + db_printf("%02x", + tlm_buf->tlb_opts[i + 2 + j]); + } + break; + case TCPOPT_FAST_OPEN: + db_printf("FO"); + if (optlen > 2) { + db_printf(" "); + } + for (j = 0; j < optlen - 2; j++) { + db_printf("%02x", + tlm_buf->tlb_opts[i + 2 + j]); + } + break; + default: + db_printf("opt=%u len=%u", opt, optlen); + break; + } + } + db_printf(">"); + } +} +static void +db_print_pru(struct tcp_log_buffer *tlm_buf) +{ + switch (tlm_buf->tlb_flex1) { + case PRU_ATTACH: + db_printf("ATTACH"); + break; + case PRU_DETACH: + db_printf("DETACH"); + break; + case PRU_BIND: + db_printf("BIND"); + break; + case PRU_LISTEN: + db_printf("LISTEN"); + break; + case PRU_CONNECT: + db_printf("CONNECT"); + break; + case PRU_ACCEPT: + db_printf("ACCEPT"); + break; + case PRU_DISCONNECT: + db_printf("DISCONNECT"); + break; + case PRU_SHUTDOWN: + db_printf("SHUTDOWN"); + break; + case PRU_RCVD: + db_printf("RCVD"); + break; + case PRU_SEND: + db_printf("SEND"); + break; + case PRU_ABORT: + db_printf("ABORT"); + break; + case PRU_CONTROL: + db_printf("CONTROL"); + break; + case PRU_SENSE: + db_printf("SENSE"); + break; + case PRU_RCVOOB: + db_printf("RCVOOB"); + break; + case PRU_SENDOOB: + db_printf("SENDOOB"); + break; + case PRU_SOCKADDR: + db_printf("SOCKADDR"); + break; + case PRU_PEERADDR: + db_printf("PEERADDR"); + break; + case PRU_CONNECT2: + db_printf("CONNECT2"); + break; + case PRU_FASTTIMO: + db_printf("FASTTIMO"); + break; + case PRU_SLOWTIMO: + db_printf("SLOWTIMO"); + break; + case PRU_PROTORCV: + db_printf("PROTORCV"); + break; + case PRU_PROTOSEND: + db_printf("PROTOSEND"); + break; + case PRU_SEND_EOF: + db_printf("SEND_EOF"); + break; + case PRU_SOSETLABEL: + db_printf("SOSETLABEL"); + break; + case PRU_CLOSE: + db_printf("CLOSE"); + break; + case PRU_FLUSH: + db_printf("FLUSH"); + break; + default: + db_printf("Unknown PRU (%u)", tlm_buf->tlb_flex1); + break; + } + if (tlm_buf->tlb_errno >= 0) { + db_printf(", error: %d", tlm_buf->tlb_errno); + } +} + +static void +db_print_rto(struct tcp_log_buffer *tlm_buf) +{ + tt_what what; + tt_which which; + + what = (tlm_buf->tlb_flex1 & 0xffffff00) >> 8; + which = tlm_buf->tlb_flex1 & 0x000000ff; + switch (what) { + case TT_PROCESSING: + db_printf("Processing "); + break; + case TT_PROCESSED: + db_printf("Processed "); + break; + case TT_STARTING: + db_printf("Starting "); + break; + case TT_STOPPING: + db_printf("Stopping "); + break; + default: + db_printf("Unknown operation (%u) for ", what); + break; + } + switch (which) { + case TT_REXMT: + db_printf("Retransmission "); + break; + case TT_PERSIST: + db_printf("Persist "); + break; + case TT_KEEP: + db_printf("Keepalive "); + break; + case TT_2MSL: + db_printf("2 MSL "); + break; + case TT_DELACK: + db_printf("Delayed ACK "); + break; + default: + db_printf("Unknown (%u) ", which); + break; + } + db_printf("timer"); + if (what == TT_STARTING) { + db_printf(": %u ms", tlm_buf->tlb_flex2); + } +} + +static void +db_print_usersend(struct tcp_log_buffer *tlm_buf) +{ + if ((tlm_buf->tlb_eventflags & TLB_FLAG_RXBUF) == 0) { + return; + } + if ((tlm_buf->tlb_eventflags & TLB_FLAG_TXBUF) == 0) { + return; + } + db_printf("usersend: rcv.acc: %u rcv.ccc: %u snd.acc: %u snd.ccc: %u", + tlm_buf->tlb_rxbuf.tls_sb_acc, tlm_buf->tlb_rxbuf.tls_sb_ccc, + tlm_buf->tlb_txbuf.tls_sb_acc, tlm_buf->tlb_txbuf.tls_sb_ccc); +} + +void +db_print_bblog_entries(struct tcp_log_stailq *log_entries, int indent) +{ + struct tcp_log_mem *log_entry; + struct tcp_log_buffer *tlm_buf, *prev_tlm_buf; + int64_t delta_t; + + indent += 2; + prev_tlm_buf = NULL; + STAILQ_FOREACH(log_entry, log_entries, tlm_queue) { + db_print_indent(indent); + tlm_buf = &log_entry->tlm_buf; + if (prev_tlm_buf == NULL) { + db_printf(" 0.000 "); + } else { + delta_t = sbttoms(tvtosbt(tlm_buf->tlb_tv) - + tvtosbt(prev_tlm_buf->tlb_tv)); + db_printf("+%u.%03u ", (uint32_t)(delta_t / 1000), + (uint32_t)(delta_t % 1000)); + } + switch (tlm_buf->tlb_eventid) { + case TCP_LOG_IN: + db_printf("< "); + db_print_tcphdr(tlm_buf); + break; + case TCP_LOG_OUT: + db_printf("> "); + db_print_tcphdr(tlm_buf); + break; + case TCP_LOG_RTO: + db_print_rto(tlm_buf); + break; + case TCP_LOG_PRU: + db_print_pru(tlm_buf); + break; + case TCP_LOG_USERSEND: + db_print_usersend(tlm_buf); + break; + default: + break; + } + db_printf("\n"); + prev_tlm_buf = tlm_buf; + if (db_pager_quit) + break; + } +} +#endif diff --git a/sys/netinet/tcp_log_buf.h b/sys/netinet/tcp_log_buf.h index 06b2998b19ed..eb33a9c15ebb 100644 --- a/sys/netinet/tcp_log_buf.h +++ b/sys/netinet/tcp_log_buf.h @@ -585,5 +585,9 @@ tcp_log_event(struct tcpcb *tp, struct tcphdr *th, struct sockbuf *rxbuf, } #endif /* TCP_BLACKBOX */ +#ifdef DDB +void db_print_bblog_entries(struct tcp_log_stailq *log_entries, int indent); +#endif + #endif /* _KERNEL */ #endif /* __tcp_log_buf_h__ */ diff --git a/sys/netinet/tcp_usrreq.c b/sys/netinet/tcp_usrreq.c index a7a1d98fd193..1eee45e3c2ac 100644 --- a/sys/netinet/tcp_usrreq.c +++ b/sys/netinet/tcp_usrreq.c @@ -3083,7 +3083,7 @@ db_print_bblog_state(int state) } static void -db_print_tcpcb(struct tcpcb *tp, const char *name, int indent) +db_print_tcpcb(struct tcpcb *tp, const char *name, int indent, bool show_bblog) { db_print_indent(indent); @@ -3208,35 +3208,42 @@ db_print_tcpcb(struct tcpcb *tp, const char *name, int indent) db_print_indent(indent); db_printf("t_lognum: %d t_loglimit: %d t_logsn: %u\n", tp->t_lognum, tp->t_loglimit, tp->t_logsn); + + if (show_bblog) { + db_print_bblog_entries(&tp->t_logs, indent); + } } DB_SHOW_COMMAND(tcpcb, db_show_tcpcb) { struct tcpcb *tp; + bool show_bblog; if (!have_addr) { db_printf("usage: show tcpcb <addr>\n"); return; } + show_bblog = strchr(modif, 'b') != NULL; tp = (struct tcpcb *)addr; - db_print_tcpcb(tp, "tcpcb", 0); + db_print_tcpcb(tp, "tcpcb", 0, show_bblog); } DB_SHOW_ALL_COMMAND(tcpcbs, db_show_all_tcpcbs) { VNET_ITERATOR_DECL(vnet_iter); struct inpcb *inp; - bool only_locked; + bool only_locked, show_bblog; only_locked = strchr(modif, 'l') != NULL; + show_bblog = strchr(modif, 'b') != NULL; VNET_FOREACH(vnet_iter) { CURVNET_SET(vnet_iter); CK_LIST_FOREACH(inp, &V_tcbinfo.ipi_listhead, inp_list) { if (only_locked && inp->inp_lock.rw_lock == RW_UNLOCKED) continue; - db_print_tcpcb(intotcpcb(inp), "tcpcb", 0); + db_print_tcpcb(intotcpcb(inp), "tcpcb", 0, show_bblog); if (db_pager_quit) break; }
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?>