Author: rrs Date: Mon Jan 6 12:48:06 2020 New Revision: 356414 URL: https://svnweb.freebsd.org/changeset/base/356414
Log: This change adds a small feature to the tcp logging code. Basically a connection can now have a separate tag added to the id. Obtained from: Lawrence Stewart Sponsored by: Netflix Inc Differential Revision: https://reviews.freebsd.org/D22866 Modified: head/sys/netinet/tcp_log_buf.c head/sys/netinet/tcp_log_buf.h head/sys/netinet/tcp_var.h Modified: head/sys/netinet/tcp_log_buf.c ============================================================================== --- head/sys/netinet/tcp_log_buf.c Mon Jan 6 10:52:13 2020 (r356413) +++ head/sys/netinet/tcp_log_buf.c Mon Jan 6 12:48:06 2020 (r356414) @@ -43,7 +43,7 @@ __FBSDID("$FreeBSD$"); #include <sys/socketvar.h> #include <sys/sysctl.h> #include <sys/tree.h> -#include <sys/stats.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> @@ -78,6 +78,7 @@ static u_long tcp_log_auto_ratio = 0; static volatile u_long tcp_log_auto_ratio_cur = 0; static uint32_t tcp_log_auto_mode = TCP_LOG_STATE_TAIL; static bool tcp_log_auto_all = false; +static uint32_t tcp_disable_all_bb_logs = 0; RB_PROTOTYPE_STATIC(tcp_log_id_tree, tcp_log_id_bucket, tlb_rb, tcp_log_id_cmp) @@ -111,6 +112,10 @@ SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_id_tcpc SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, log_version, CTLFLAG_RD, &tcp_log_version, 0, "Version of log formats exported"); +SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, disable_all, CTLFLAG_RW, + &tcp_disable_all_bb_logs, TCP_LOG_STATE_HEAD_AUTO, + "Disable all BB logging for all connections"); + SYSCTL_ULONG(_net_inet_tcp_bb, OID_AUTO, log_auto_ratio, CTLFLAG_RW, &tcp_log_auto_ratio, 0, "Do auto capturing for 1 out of N sessions"); @@ -156,7 +161,18 @@ SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, freed, #ifdef INVARIANTS #define TCPLOG_DEBUG_RINGBUF #endif +/* Number of requests to consider a PBCID "active". */ +#define ACTIVE_REQUEST_COUNT 10 +/* Statistic tracking for "active" PBCIDs. */ +static counter_u64_t tcp_log_pcb_ids_cur; +static counter_u64_t tcp_log_pcb_ids_tot; + +SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_cur, CTLFLAG_RD, + &tcp_log_pcb_ids_cur, "Number of pcb IDs allocated in the system"); +SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_tot, CTLFLAG_RD, + &tcp_log_pcb_ids_tot, "Total number of pcb IDs that have been allocated"); + struct tcp_log_mem { STAILQ_ENTRY(tcp_log_mem) tlm_queue; @@ -240,10 +256,14 @@ struct tcp_log_id_bucket * (struct tcp_log_id_bucket *) and (char *) interchangeably. */ char tlb_id[TCP_LOG_ID_LEN]; + char tlb_tag[TCP_LOG_TAG_LEN]; RB_ENTRY(tcp_log_id_bucket) tlb_rb; struct tcp_log_id_head tlb_head; struct mtx tlb_mtx; volatile u_int tlb_refcnt; + volatile u_int tlb_reqcnt; + uint32_t tlb_loglimit; + uint8_t tlb_logstate; }; struct tcp_log_id_node @@ -285,6 +305,7 @@ tcp_log_selectauto(void) * this session. */ if (tcp_log_auto_ratio && + (tcp_disable_all_bb_logs == 0) && (atomic_fetchadd_long(&tcp_log_auto_ratio_cur, 1) % tcp_log_auto_ratio) == 0) return (true); @@ -337,6 +358,7 @@ tcp_log_remove_bucket(struct tcp_log_id_bucket *tlb) #endif } TCPID_BUCKET_LOCK_DESTROY(tlb); + counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1); uma_zfree(tcp_log_bucket_zone, tlb); } @@ -484,7 +506,53 @@ tcp_log_grow_tlb(char *tlb_id, struct tcpcb *tp) #endif } +static void +tcp_log_increment_reqcnt(struct tcp_log_id_bucket *tlb) +{ + + atomic_fetchadd_int(&tlb->tlb_reqcnt, 1); +} + /* + * Associate the specified tag with a particular TCP log ID. + * Called with INPCB locked. Returns with it unlocked. + * Returns 0 on success or EOPNOTSUPP if the connection has no TCP log ID. + */ +int +tcp_log_set_tag(struct tcpcb *tp, char *tag) +{ + struct tcp_log_id_bucket *tlb; + int tree_locked; + + INP_WLOCK_ASSERT(tp->t_inpcb); + + tree_locked = TREE_UNLOCKED; + tlb = tp->t_lib; + if (tlb == NULL) { + INP_WUNLOCK(tp->t_inpcb); + return (EOPNOTSUPP); + } + + TCPID_BUCKET_REF(tlb); + INP_WUNLOCK(tp->t_inpcb); + TCPID_BUCKET_LOCK(tlb); + strlcpy(tlb->tlb_tag, tag, TCP_LOG_TAG_LEN); + if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL)) + TCPID_BUCKET_UNLOCK(tlb); + + if (tree_locked == TREE_WLOCKED) { + TCPID_TREE_WLOCK_ASSERT(); + TCPID_TREE_WUNLOCK(); + } else if (tree_locked == TREE_RLOCKED) { + TCPID_TREE_RLOCK_ASSERT(); + TCPID_TREE_RUNLOCK(); + } else + TCPID_TREE_UNLOCK_ASSERT(); + + return (0); +} + +/* * Set the TCP log ID for a TCPCB. * Called with INPCB locked. Returns with it unlocked. */ @@ -509,6 +577,21 @@ restart: /* See if the ID is unchanged. */ if ((tp->t_lib != NULL && !strcmp(tp->t_lib->tlb_id, id)) || (tp->t_lib == NULL && *id == 0)) { + if (tp->t_lib != NULL) { + tcp_log_increment_reqcnt(tp->t_lib); + if ((tp->t_lib->tlb_logstate) && + (tp->t_log_state_set == 0)) { + /* Clone in any logging */ + + tp->t_logstate = tp->t_lib->tlb_logstate; + } + if ((tp->t_lib->tlb_loglimit) && + (tp->t_log_state_set == 0)) { + /* We also have a limit set */ + + tp->t_loglimit = tp->t_lib->tlb_loglimit; + } + } rv = 0; goto done; } @@ -677,7 +760,19 @@ refind: rv = ENOBUFS; goto done_noinp; } + counter_u64_add(tcp_log_pcb_ids_cur, 1); + counter_u64_add(tcp_log_pcb_ids_tot, 1); + if ((tcp_log_auto_all == false) && + tcp_log_auto_mode && + tcp_log_selectauto()) { + /* Save off the log state */ + tlb->tlb_logstate = tcp_log_auto_mode; + } else + tlb->tlb_logstate = TCP_LOG_STATE_OFF; + tlb->tlb_loglimit = 0; + tlb->tlb_tag[0] = '\0'; /* Default to an empty tag. */ + /* * Copy the ID to the bucket. * NB: Don't use strlcpy() unless you are sure @@ -699,6 +794,7 @@ refind: */ SLIST_INIT(&tlb->tlb_head); refcount_init(&tlb->tlb_refcnt, 1); + tlb->tlb_reqcnt = 1; memset(&tlb->tlb_mtx, 0, sizeof(struct mtx)); TCPID_BUCKET_LOCK_INIT(tlb); TCPID_BUCKET_LOCK(tlb); @@ -707,6 +803,8 @@ refind: #define FREE_NEW_TLB() do { \ TCPID_BUCKET_LOCK_DESTROY(tlb); \ uma_zfree(tcp_log_bucket_zone, tlb); \ + counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1); \ + counter_u64_add(tcp_log_pcb_ids_tot, (int64_t)-1); \ bucket_locked = false; \ tlb = NULL; \ } while (0) @@ -762,6 +860,9 @@ refind: /* Take a reference on the bucket. */ TCPID_BUCKET_REF(tlb); + + /* Record the request. */ + tcp_log_increment_reqcnt(tlb); } tcp_log_grow_tlb(tlb->tlb_id, tp); @@ -770,6 +871,16 @@ refind: SLIST_INSERT_HEAD(&tlb->tlb_head, tln, tln_list); tp->t_lib = tlb; tp->t_lin = tln; + if (tp->t_lib->tlb_logstate) { + /* Clone in any logging */ + + tp->t_logstate = tp->t_lib->tlb_logstate; + } + if (tp->t_lib->tlb_loglimit) { + /* The loglimit too */ + + tp->t_loglimit = tp->t_lib->tlb_loglimit; + } tln = NULL; } @@ -823,6 +934,52 @@ tcp_log_get_id(struct tcpcb *tp, char *buf) } /* + * Get the tag associated with the TCPCB's log ID. + * Called with INPCB locked. Returns with it unlocked. + * 'buf' must point to a buffer that is at least TCP_LOG_TAG_LEN bytes long. + * Returns number of bytes copied. + */ +size_t +tcp_log_get_tag(struct tcpcb *tp, char *buf) +{ + struct tcp_log_id_bucket *tlb; + size_t len; + int tree_locked; + + INP_WLOCK_ASSERT(tp->t_inpcb); + + tree_locked = TREE_UNLOCKED; + tlb = tp->t_lib; + + if (tlb != NULL) { + TCPID_BUCKET_REF(tlb); + INP_WUNLOCK(tp->t_inpcb); + TCPID_BUCKET_LOCK(tlb); + len = strlcpy(buf, tlb->tlb_tag, TCP_LOG_TAG_LEN); + KASSERT(len < TCP_LOG_TAG_LEN, + ("%s:%d: tp->t_lib->tlb_tag too long (%zu)", + __func__, __LINE__, len)); + if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL)) + TCPID_BUCKET_UNLOCK(tlb); + + if (tree_locked == TREE_WLOCKED) { + TCPID_TREE_WLOCK_ASSERT(); + TCPID_TREE_WUNLOCK(); + } else if (tree_locked == TREE_RLOCKED) { + TCPID_TREE_RLOCK_ASSERT(); + TCPID_TREE_RUNLOCK(); + } else + TCPID_TREE_UNLOCK_ASSERT(); + } else { + INP_WUNLOCK(tp->t_inpcb); + *buf = '\0'; + len = 0; + } + + return (len); +} + +/* * Get number of connections with the same log ID. * Log ID is taken from given TCPCB. * Called with INPCB locked. @@ -1005,6 +1162,8 @@ tcp_log_init(void) tcp_log_que_read = counter_u64_alloc(M_WAITOK); tcp_log_que_freed = counter_u64_alloc(M_WAITOK); #endif + tcp_log_pcb_ids_cur = counter_u64_alloc(M_WAITOK); + tcp_log_pcb_ids_tot = counter_u64_alloc(M_WAITOK); rw_init_flags(&tcp_id_tree_lock, "TCP ID tree", RW_NEW); mtx_init(&tcp_log_expireq_mtx, "TCP log expireq", NULL, MTX_DEF); @@ -1023,7 +1182,10 @@ tcp_log_tcpcbinit(struct tcpcb *tp) * If we are doing auto-capturing, figure out whether we will capture * this session. */ - if (tcp_log_selectauto()) { + tp->t_loglimit = tcp_log_session_limit; + if ((tcp_log_auto_all == true) && + tcp_log_auto_mode && + tcp_log_selectauto()) { tp->t_logstate = tcp_log_auto_mode; tp->t_flags2 |= TF2_LOG_AUTO; } @@ -1162,6 +1324,8 @@ tcp_log_tcpcbfini(struct tcpcb *tp) INP_WLOCK_ASSERT(tp->t_inpcb); + TCP_LOG_EVENT(tp, NULL, NULL, NULL, TCP_LOG_CONNEND, 0, 0, NULL, false); + /* * If we were gathering packets to be automatically dumped, try to do * it now. If this succeeds, the log information in the TCPCB will be @@ -1327,6 +1491,25 @@ tcp_log_tcpcbfini(struct tcpcb *tp) tp->t_logstate = TCP_LOG_STATE_OFF; } +static void +tcp_log_purge_tp_logbuf(struct tcpcb *tp) +{ + struct tcp_log_mem *log_entry; + struct inpcb *inp; + + inp = tp->t_inpcb; + INP_WLOCK_ASSERT(inp); + if (tp->t_lognum == 0) + return; + + while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL) + tcp_log_remove_log_head(tp, log_entry); + KASSERT(tp->t_lognum == 0, + ("%s: After freeing entries, tp->t_lognum=%d (expected 0)", + __func__, tp->t_lognum)); + tp->t_logstate = TCP_LOG_STATE_OFF; +} + /* * This logs an event for a TCP socket. Normally, this is called via * TCP_LOG_EVENT or TCP_LOG_EVENT_VERBOSE. See the documentation for @@ -1350,7 +1533,17 @@ tcp_log_event_(struct tcpcb *tp, struct tcphdr *th, st __func__, func, line)); INP_WLOCK_ASSERT(tp->t_inpcb); - + if (tcp_disable_all_bb_logs) { + /* + * The global shutdown logging + * switch has been thrown. Call + * the purge function that frees + * purges out the logs and + * turns off logging. + */ + tcp_log_purge_tp_logbuf(tp); + return (NULL); + } KASSERT(tp->t_logstate == TCP_LOG_STATE_HEAD || tp->t_logstate == TCP_LOG_STATE_TAIL || tp->t_logstate == TCP_LOG_STATE_CONTINUAL || @@ -1371,7 +1564,7 @@ tcp_log_event_(struct tcpcb *tp, struct tcphdr *th, st * here. */ retry: - if (tp->t_lognum < tcp_log_session_limit) { + if (tp->t_lognum < tp->t_loglimit) { if ((log_entry = uma_zalloc(tcp_log_zone, M_NOWAIT)) != NULL) tp->t_lognum++; } else @@ -1574,7 +1767,10 @@ tcp_log_state_change(struct tcpcb *tp, int state) default: return (EINVAL); } - + if (tcp_disable_all_bb_logs) { + /* We are prohibited from doing any logs */ + tp->t_logstate = TCP_LOG_STATE_OFF; + } tp->t_flags2 &= ~(TF2_LOG_AUTO); return (0); @@ -1934,6 +2130,7 @@ tcp_log_expandlogbuf(struct tcp_log_dev_queue *param) hdr->tlh_af = entry->tldl_af; getboottime(&hdr->tlh_offset); strlcpy(hdr->tlh_id, entry->tldl_id, TCP_LOG_ID_LEN); + strlcpy(hdr->tlh_tag, entry->tldl_tag, TCP_LOG_TAG_LEN); strlcpy(hdr->tlh_reason, entry->tldl_reason, TCP_LOG_REASON_LEN); return ((struct tcp_log_common_header *)hdr); } @@ -2026,10 +2223,13 @@ tcp_log_dump_tp_logbuf(struct tcpcb *tp, char *reason, } /* Fill in the unique parts of the queue entry. */ - if (tp->t_lib != NULL) + if (tp->t_lib != NULL) { strlcpy(entry->tldl_id, tp->t_lib->tlb_id, TCP_LOG_ID_LEN); - else + strlcpy(entry->tldl_tag, tp->t_lib->tlb_tag, TCP_LOG_TAG_LEN); + } else { strlcpy(entry->tldl_id, "UNKNOWN", TCP_LOG_ID_LEN); + strlcpy(entry->tldl_tag, "UNKNOWN", TCP_LOG_TAG_LEN); + } if (reason != NULL) strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN); else @@ -2119,6 +2319,7 @@ tcp_log_dump_node_logbuf(struct tcp_log_id_node *tln, /* Fill in the unique parts of the queue entry. */ strlcpy(entry->tldl_id, tlb->tlb_id, TCP_LOG_ID_LEN); + strlcpy(entry->tldl_tag, tlb->tlb_tag, TCP_LOG_TAG_LEN); if (reason != NULL) strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN); else Modified: head/sys/netinet/tcp_log_buf.h ============================================================================== --- head/sys/netinet/tcp_log_buf.h Mon Jan 6 10:52:13 2020 (r356413) +++ head/sys/netinet/tcp_log_buf.h Mon Jan 6 12:48:06 2020 (r356414) @@ -31,7 +31,8 @@ #define __tcp_log_buf_h__ #define TCP_LOG_REASON_LEN 32 -#define TCP_LOG_BUF_VER (6) +#define TCP_LOG_TAG_LEN 32 +#define TCP_LOG_BUF_VER (7) /* * Because the (struct tcp_log_buffer) includes 8-byte uint64_t's, it requires @@ -263,6 +264,7 @@ struct tcp_log_header { struct timeval tlh_offset; /* Uptime -> UTC offset */ char tlh_id[TCP_LOG_ID_LEN]; char tlh_reason[TCP_LOG_REASON_LEN]; + char tlh_tag[TCP_LOG_TAG_LEN]; uint8_t tlh_af; uint8_t _pad[7]; } ALIGN_TCP_LOG; @@ -272,6 +274,7 @@ struct tcp_log_dev_log_queue { struct tcp_log_dev_queue tldl_common; char tldl_id[TCP_LOG_ID_LEN]; char tldl_reason[TCP_LOG_REASON_LEN]; + char tldl_tag[TCP_LOG_TAG_LEN]; struct in_endpoints tldl_ie; struct tcp_log_stailq tldl_entries; int tldl_count; @@ -349,10 +352,12 @@ struct tcp_log_buffer *tcp_log_event_(struct tcpcb *tp union tcp_log_stackspecific *stackinfo, int th_hostorder, const char *output_caller, const char *func, int line, const struct timeval *tv); size_t tcp_log_get_id(struct tcpcb *tp, char *buf); +size_t tcp_log_get_tag(struct tcpcb *tp, char *buf); u_int tcp_log_get_id_cnt(struct tcpcb *tp); int tcp_log_getlogbuf(struct sockopt *sopt, struct tcpcb *tp); void tcp_log_init(void); int tcp_log_set_id(struct tcpcb *tp, char *id); +int tcp_log_set_tag(struct tcpcb *tp, char *tag); int tcp_log_state_change(struct tcpcb *tp, int state); void tcp_log_tcpcbinit(struct tcpcb *tp); void tcp_log_tcpcbfini(struct tcpcb *tp); Modified: head/sys/netinet/tcp_var.h ============================================================================== --- head/sys/netinet/tcp_var.h Mon Jan 6 10:52:13 2020 (r356413) +++ head/sys/netinet/tcp_var.h Mon Jan 6 12:48:06 2020 (r356414) @@ -103,7 +103,8 @@ struct tcpcb { t_idle_reduce : 1, t_delayed_ack: 7, /* Delayed ack variable */ t_fin_is_rst: 1, /* Are fin's treated as resets */ - bits_spare : 3; + t_log_state_set: 1, + bits_spare : 2; u_int t_flags; tcp_seq snd_una; /* sent but unacknowledged */ tcp_seq snd_max; /* highest sequence number sent; @@ -206,6 +207,7 @@ struct tcpcb { u_int t_keepcnt; /* number of keepalives before close */ int t_dupacks; /* consecutive dup acks recd */ int t_lognum; /* Number of log entries */ + int t_loglimit; /* Maximum number of log entries */ struct tcp_log_stailq t_logs; /* Log buffer */ struct tcp_log_id_node *t_lin; struct tcp_log_id_bucket *t_lib; _______________________________________________ svn-src-all@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/svn-src-all To unsubscribe, send any mail to "svn-src-all-unsubscr...@freebsd.org"
