svn commit: r356414 - head/sys/netinet
Randall Stewart
rrs at FreeBSD.org
Mon Jan 6 12:48:07 UTC 2020
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;
More information about the svn-src-all
mailing list