2 * SPDX-License-Identifier: BSD-2-Clause-FreeBSD
4 * Copyright (c) 2016-2018 Netflix, Inc.
6 * Redistribution and use in source and binary forms, with or without
7 * modification, are permitted provided that the following conditions
9 * 1. Redistributions of source code must retain the above copyright
10 * notice, this list of conditions and the following disclaimer.
11 * 2. Redistributions in binary form must reproduce the above copyright
12 * notice, this list of conditions and the following disclaimer in the
13 * documentation and/or other materials provided with the distribution.
15 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
16 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
17 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
18 * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
19 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
20 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
21 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
22 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
23 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
24 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
29 #include <sys/cdefs.h>
30 __FBSDID("$FreeBSD$");
32 #include <sys/param.h>
34 #include <sys/kernel.h>
36 #include <sys/malloc.h>
37 #include <sys/mutex.h>
38 #include <sys/qmath.h>
39 #include <sys/queue.h>
40 #include <sys/refcount.h>
41 #include <sys/rwlock.h>
42 #include <sys/socket.h>
43 #include <sys/socketvar.h>
44 #include <sys/sysctl.h>
46 #include <sys/stats.h> /* Must come after qmath.h and tree.h */
47 #include <sys/counter.h>
49 #include <dev/tcp_log/tcp_log_dev.h>
52 #include <net/if_var.h>
55 #include <netinet/in.h>
56 #include <netinet/in_pcb.h>
57 #include <netinet/in_var.h>
58 #include <netinet/tcp_var.h>
59 #include <netinet/tcp_log_buf.h>
61 /* Default expiry time */
62 #define TCP_LOG_EXPIRE_TIME ((sbintime_t)60 * SBT_1S)
64 /* Max interval at which to run the expiry timer */
65 #define TCP_LOG_EXPIRE_INTVL ((sbintime_t)5 * SBT_1S)
68 static uma_zone_t tcp_log_bucket_zone, tcp_log_node_zone, tcp_log_zone;
69 static int tcp_log_session_limit = TCP_LOG_BUF_DEFAULT_SESSION_LIMIT;
70 static uint32_t tcp_log_version = TCP_LOG_BUF_VER;
71 RB_HEAD(tcp_log_id_tree, tcp_log_id_bucket);
72 static struct tcp_log_id_tree tcp_log_id_head;
73 static STAILQ_HEAD(, tcp_log_id_node) tcp_log_expireq_head =
74 STAILQ_HEAD_INITIALIZER(tcp_log_expireq_head);
75 static struct mtx tcp_log_expireq_mtx;
76 static struct callout tcp_log_expireq_callout;
77 static u_long tcp_log_auto_ratio = 0;
78 static volatile u_long tcp_log_auto_ratio_cur = 0;
79 static uint32_t tcp_log_auto_mode = TCP_LOG_STATE_TAIL;
80 static bool tcp_log_auto_all = false;
81 static uint32_t tcp_disable_all_bb_logs = 0;
83 RB_PROTOTYPE_STATIC(tcp_log_id_tree, tcp_log_id_bucket, tlb_rb, tcp_log_id_cmp)
85 SYSCTL_NODE(_net_inet_tcp, OID_AUTO, bb, CTLFLAG_RW, 0, "TCP Black Box controls");
87 SYSCTL_BOOL(_net_inet_tcp_bb, OID_AUTO, log_verbose, CTLFLAG_RW, &tcp_log_verbose,
88 0, "Force verbose logging for TCP traces");
90 SYSCTL_INT(_net_inet_tcp_bb, OID_AUTO, log_session_limit,
91 CTLFLAG_RW, &tcp_log_session_limit, 0,
92 "Maximum number of events maintained for each TCP session");
94 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_global_limit, CTLFLAG_RW,
95 &tcp_log_zone, "Maximum number of events maintained for all TCP sessions");
97 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_global_entries, CTLFLAG_RD,
98 &tcp_log_zone, "Current number of events maintained for all TCP sessions");
100 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_id_limit, CTLFLAG_RW,
101 &tcp_log_bucket_zone, "Maximum number of log IDs");
103 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_id_entries, CTLFLAG_RD,
104 &tcp_log_bucket_zone, "Current number of log IDs");
106 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_id_tcpcb_limit, CTLFLAG_RW,
107 &tcp_log_node_zone, "Maximum number of tcpcbs with log IDs");
109 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_id_tcpcb_entries, CTLFLAG_RD,
110 &tcp_log_node_zone, "Current number of tcpcbs with log IDs");
112 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, log_version, CTLFLAG_RD, &tcp_log_version,
113 0, "Version of log formats exported");
115 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, disable_all, CTLFLAG_RW,
116 &tcp_disable_all_bb_logs, TCP_LOG_STATE_HEAD_AUTO,
117 "Disable all BB logging for all connections");
119 SYSCTL_ULONG(_net_inet_tcp_bb, OID_AUTO, log_auto_ratio, CTLFLAG_RW,
120 &tcp_log_auto_ratio, 0, "Do auto capturing for 1 out of N sessions");
122 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, log_auto_mode, CTLFLAG_RW,
123 &tcp_log_auto_mode, TCP_LOG_STATE_HEAD_AUTO,
124 "Logging mode for auto-selected sessions (default is TCP_LOG_STATE_HEAD_AUTO)");
126 SYSCTL_BOOL(_net_inet_tcp_bb, OID_AUTO, log_auto_all, CTLFLAG_RW,
127 &tcp_log_auto_all, false,
128 "Auto-select from all sessions (rather than just those with IDs)");
130 #ifdef TCPLOG_DEBUG_COUNTERS
131 counter_u64_t tcp_log_queued;
132 counter_u64_t tcp_log_que_fail1;
133 counter_u64_t tcp_log_que_fail2;
134 counter_u64_t tcp_log_que_fail3;
135 counter_u64_t tcp_log_que_fail4;
136 counter_u64_t tcp_log_que_fail5;
137 counter_u64_t tcp_log_que_copyout;
138 counter_u64_t tcp_log_que_read;
139 counter_u64_t tcp_log_que_freed;
141 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, queued, CTLFLAG_RD,
142 &tcp_log_queued, "Number of entries queued");
143 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail1, CTLFLAG_RD,
144 &tcp_log_que_fail1, "Number of entries queued but fail 1");
145 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail2, CTLFLAG_RD,
146 &tcp_log_que_fail2, "Number of entries queued but fail 2");
147 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail3, CTLFLAG_RD,
148 &tcp_log_que_fail3, "Number of entries queued but fail 3");
149 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail4, CTLFLAG_RD,
150 &tcp_log_que_fail4, "Number of entries queued but fail 4");
151 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail5, CTLFLAG_RD,
152 &tcp_log_que_fail5, "Number of entries queued but fail 4");
153 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, copyout, CTLFLAG_RD,
154 &tcp_log_que_copyout, "Number of entries copied out");
155 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, read, CTLFLAG_RD,
156 &tcp_log_que_read, "Number of entries read from the queue");
157 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, freed, CTLFLAG_RD,
158 &tcp_log_que_freed, "Number of entries freed after reading");
162 #define TCPLOG_DEBUG_RINGBUF
164 /* Number of requests to consider a PBCID "active". */
165 #define ACTIVE_REQUEST_COUNT 10
167 /* Statistic tracking for "active" PBCIDs. */
168 static counter_u64_t tcp_log_pcb_ids_cur;
169 static counter_u64_t tcp_log_pcb_ids_tot;
171 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_cur, CTLFLAG_RD,
172 &tcp_log_pcb_ids_cur, "Number of pcb IDs allocated in the system");
173 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_tot, CTLFLAG_RD,
174 &tcp_log_pcb_ids_tot, "Total number of pcb IDs that have been allocated");
178 STAILQ_ENTRY(tcp_log_mem) tlm_queue;
179 struct tcp_log_buffer tlm_buf;
180 struct tcp_log_verbose tlm_v;
181 #ifdef TCPLOG_DEBUG_RINGBUF
182 volatile int tlm_refcnt;
186 /* 60 bytes for the header, + 16 bytes for padding */
187 static uint8_t zerobuf[76];
196 * A. You need a lock on the Tree to add/remove buckets.
197 * B. You need a lock on the bucket to add/remove nodes from the bucket.
198 * C. To change information in a node, you need the INP lock if the tln_closed
199 * field is false. Otherwise, you need the bucket lock. (Note that the
200 * tln_closed field can change at any point, so you need to recheck the
201 * entry after acquiring the INP lock.)
202 * D. To remove a node from the bucket, you must have that entry locked,
203 * according to the criteria of Rule C. Also, the node must not be on
205 * E. The exception to C is the expiry queue fields, which are locked by
206 * the TCPLOG_EXPIREQ lock.
208 * Buckets have a reference count. Each node is a reference. Further,
209 * other callers may add reference counts to keep a bucket from disappearing.
210 * You can add a reference as long as you own a lock sufficient to keep the
211 * bucket from disappearing. For example, a common use is:
212 * a. Have a locked INP, but need to lock the TCPID_BUCKET.
213 * b. Add a refcount on the bucket. (Safe because the INP lock prevents
214 * the TCPID_BUCKET from going away.)
215 * c. Drop the INP lock.
216 * d. Acquire a lock on the TCPID_BUCKET.
217 * e. Acquire a lock on the INP.
218 * f. Drop the refcount on the bucket.
219 * (At this point, the bucket may disappear.)
222 * You can acquire this with either the bucket or INP lock. Don't reverse it.
223 * When the expire code has committed to freeing a node, it resets the expiry
224 * time to SBT_MAX. That is the signal to everyone else that they should
225 * leave that node alone.
227 static struct rwlock tcp_id_tree_lock;
228 #define TCPID_TREE_WLOCK() rw_wlock(&tcp_id_tree_lock)
229 #define TCPID_TREE_RLOCK() rw_rlock(&tcp_id_tree_lock)
230 #define TCPID_TREE_UPGRADE() rw_try_upgrade(&tcp_id_tree_lock)
231 #define TCPID_TREE_WUNLOCK() rw_wunlock(&tcp_id_tree_lock)
232 #define TCPID_TREE_RUNLOCK() rw_runlock(&tcp_id_tree_lock)
233 #define TCPID_TREE_WLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_WLOCKED)
234 #define TCPID_TREE_RLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_RLOCKED)
235 #define TCPID_TREE_UNLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_UNLOCKED)
237 #define TCPID_BUCKET_LOCK_INIT(tlb) mtx_init(&((tlb)->tlb_mtx), "tcp log id bucket", NULL, MTX_DEF)
238 #define TCPID_BUCKET_LOCK_DESTROY(tlb) mtx_destroy(&((tlb)->tlb_mtx))
239 #define TCPID_BUCKET_LOCK(tlb) mtx_lock(&((tlb)->tlb_mtx))
240 #define TCPID_BUCKET_UNLOCK(tlb) mtx_unlock(&((tlb)->tlb_mtx))
241 #define TCPID_BUCKET_LOCK_ASSERT(tlb) mtx_assert(&((tlb)->tlb_mtx), MA_OWNED)
242 #define TCPID_BUCKET_UNLOCK_ASSERT(tlb) mtx_assert(&((tlb)->tlb_mtx), MA_NOTOWNED)
244 #define TCPID_BUCKET_REF(tlb) refcount_acquire(&((tlb)->tlb_refcnt))
245 #define TCPID_BUCKET_UNREF(tlb) refcount_release(&((tlb)->tlb_refcnt))
247 #define TCPLOG_EXPIREQ_LOCK() mtx_lock(&tcp_log_expireq_mtx)
248 #define TCPLOG_EXPIREQ_UNLOCK() mtx_unlock(&tcp_log_expireq_mtx)
250 SLIST_HEAD(tcp_log_id_head, tcp_log_id_node);
252 struct tcp_log_id_bucket
255 * tlb_id must be first. This lets us use strcmp on
256 * (struct tcp_log_id_bucket *) and (char *) interchangeably.
258 char tlb_id[TCP_LOG_ID_LEN];
259 char tlb_tag[TCP_LOG_TAG_LEN];
260 RB_ENTRY(tcp_log_id_bucket) tlb_rb;
261 struct tcp_log_id_head tlb_head;
263 volatile u_int tlb_refcnt;
264 volatile u_int tlb_reqcnt;
265 uint32_t tlb_loglimit;
266 uint8_t tlb_logstate;
269 struct tcp_log_id_node
271 SLIST_ENTRY(tcp_log_id_node) tln_list;
272 STAILQ_ENTRY(tcp_log_id_node) tln_expireq; /* Locked by the expireq lock */
273 sbintime_t tln_expiretime; /* Locked by the expireq lock */
276 * If INP is NULL, that means the connection has closed. We've
277 * saved the connection endpoint information and the log entries
278 * in the tln_ie and tln_entries members. We've also saved a pointer
279 * to the enclosing bucket here. If INP is not NULL, the information is
280 * in the PCB and not here.
282 struct inpcb *tln_inp;
283 struct tcpcb *tln_tp;
284 struct tcp_log_id_bucket *tln_bucket;
285 struct in_endpoints tln_ie;
286 struct tcp_log_stailq tln_entries;
288 volatile int tln_closed;
292 enum tree_lock_state {
298 /* Do we want to select this session for auto-logging? */
300 tcp_log_selectauto(void)
304 * If we are doing auto-capturing, figure out whether we will capture
307 if (tcp_log_auto_ratio &&
308 (tcp_disable_all_bb_logs == 0) &&
309 (atomic_fetchadd_long(&tcp_log_auto_ratio_cur, 1) %
310 tcp_log_auto_ratio) == 0)
316 tcp_log_id_cmp(struct tcp_log_id_bucket *a, struct tcp_log_id_bucket *b)
318 KASSERT(a != NULL, ("tcp_log_id_cmp: argument a is unexpectedly NULL"));
319 KASSERT(b != NULL, ("tcp_log_id_cmp: argument b is unexpectedly NULL"));
320 return strncmp(a->tlb_id, b->tlb_id, TCP_LOG_ID_LEN);
323 RB_GENERATE_STATIC(tcp_log_id_tree, tcp_log_id_bucket, tlb_rb, tcp_log_id_cmp)
326 tcp_log_id_validate_tree_lock(int tree_locked)
330 switch (tree_locked) {
332 TCPID_TREE_WLOCK_ASSERT();
335 TCPID_TREE_RLOCK_ASSERT();
338 TCPID_TREE_UNLOCK_ASSERT();
341 kassert_panic("%s:%d: unknown tree lock state", __func__,
348 tcp_log_remove_bucket(struct tcp_log_id_bucket *tlb)
351 TCPID_TREE_WLOCK_ASSERT();
352 KASSERT(SLIST_EMPTY(&tlb->tlb_head),
353 ("%s: Attempt to remove non-empty bucket", __func__));
354 if (RB_REMOVE(tcp_log_id_tree, &tcp_log_id_head, tlb) == NULL) {
356 kassert_panic("%s:%d: error removing element from tree",
360 TCPID_BUCKET_LOCK_DESTROY(tlb);
361 counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1);
362 uma_zfree(tcp_log_bucket_zone, tlb);
366 * Call with a referenced and locked bucket.
367 * Will return true if the bucket was freed; otherwise, false.
368 * tlb: The bucket to unreference.
369 * tree_locked: A pointer to the state of the tree lock. If the tree lock
370 * state changes, the function will update it.
371 * inp: If not NULL and the function needs to drop the inp lock to relock the
372 * tree, it will do so. (The caller must ensure inp will not become invalid,
373 * probably by holding a reference to it.)
376 tcp_log_unref_bucket(struct tcp_log_id_bucket *tlb, int *tree_locked,
380 KASSERT(tlb != NULL, ("%s: called with NULL tlb", __func__));
381 KASSERT(tree_locked != NULL, ("%s: called with NULL tree_locked",
384 tcp_log_id_validate_tree_lock(*tree_locked);
387 * Did we hold the last reference on the tlb? If so, we may need
388 * to free it. (Note that we can realistically only execute the
389 * loop twice: once without a write lock and once with a write
392 while (TCPID_BUCKET_UNREF(tlb)) {
394 * We need a write lock on the tree to free this.
395 * If we can upgrade the tree lock, this is "easy". If we
396 * can't upgrade the tree lock, we need to do this the
397 * "hard" way: unwind all our locks and relock everything.
398 * In the meantime, anything could have changed. We even
399 * need to validate that we still need to free the bucket.
401 if (*tree_locked == TREE_RLOCKED && TCPID_TREE_UPGRADE())
402 *tree_locked = TREE_WLOCKED;
403 else if (*tree_locked != TREE_WLOCKED) {
404 TCPID_BUCKET_REF(tlb);
407 TCPID_BUCKET_UNLOCK(tlb);
408 if (*tree_locked == TREE_RLOCKED)
409 TCPID_TREE_RUNLOCK();
411 *tree_locked = TREE_WLOCKED;
412 TCPID_BUCKET_LOCK(tlb);
419 * We have an empty bucket and a write lock on the tree.
420 * Remove the empty bucket.
422 tcp_log_remove_bucket(tlb);
429 * Call with a locked bucket. This function will release the lock on the
430 * bucket before returning.
432 * The caller is responsible for freeing the tp->t_lin/tln node!
434 * Note: one of tp or both tlb and tln must be supplied.
436 * inp: A pointer to the inp. If the function needs to drop the inp lock to
437 * acquire the tree write lock, it will do so. (The caller must ensure inp
438 * will not become invalid, probably by holding a reference to it.)
439 * tp: A pointer to the tcpcb. (optional; if specified, tlb and tln are ignored)
440 * tlb: A pointer to the bucket. (optional; ignored if tp is specified)
441 * tln: A pointer to the node. (optional; ignored if tp is specified)
442 * tree_locked: A pointer to the state of the tree lock. If the tree lock
443 * state changes, the function will update it.
445 * Will return true if the INP lock was reacquired; otherwise, false.
448 tcp_log_remove_id_node(struct inpcb *inp, struct tcpcb *tp,
449 struct tcp_log_id_bucket *tlb, struct tcp_log_id_node *tln,
452 int orig_tree_locked;
454 KASSERT(tp != NULL || (tlb != NULL && tln != NULL),
455 ("%s: called with tp=%p, tlb=%p, tln=%p", __func__,
457 KASSERT(tree_locked != NULL, ("%s: called with NULL tree_locked",
463 KASSERT(tlb != NULL, ("%s: unexpectedly NULL tlb", __func__));
464 KASSERT(tln != NULL, ("%s: unexpectedly NULL tln", __func__));
467 tcp_log_id_validate_tree_lock(*tree_locked);
468 TCPID_BUCKET_LOCK_ASSERT(tlb);
471 * Remove the node, clear the log bucket and node from the TCPCB, and
472 * decrement the bucket refcount. In the process, if this is the
473 * last reference, the bucket will be freed.
475 SLIST_REMOVE(&tlb->tlb_head, tln, tcp_log_id_node, tln_list);
480 orig_tree_locked = *tree_locked;
481 if (!tcp_log_unref_bucket(tlb, tree_locked, inp))
482 TCPID_BUCKET_UNLOCK(tlb);
483 return (*tree_locked != orig_tree_locked);
486 #define RECHECK_INP_CLEAN(cleanup) do { \
487 if (inp->inp_flags & (INP_TIMEWAIT | INP_DROPPED)) { \
492 tp = intotcpcb(inp); \
495 #define RECHECK_INP() RECHECK_INP_CLEAN(/* noop */)
498 tcp_log_grow_tlb(char *tlb_id, struct tcpcb *tp)
501 INP_WLOCK_ASSERT(tp->t_inpcb);
504 if (V_tcp_perconn_stats_enable == 2 && tp->t_stats == NULL)
505 (void)tcp_stats_sample_rollthedice(tp, tlb_id, strlen(tlb_id));
510 tcp_log_increment_reqcnt(struct tcp_log_id_bucket *tlb)
513 atomic_fetchadd_int(&tlb->tlb_reqcnt, 1);
517 * Associate the specified tag with a particular TCP log ID.
518 * Called with INPCB locked. Returns with it unlocked.
519 * Returns 0 on success or EOPNOTSUPP if the connection has no TCP log ID.
522 tcp_log_set_tag(struct tcpcb *tp, char *tag)
524 struct tcp_log_id_bucket *tlb;
527 INP_WLOCK_ASSERT(tp->t_inpcb);
529 tree_locked = TREE_UNLOCKED;
532 INP_WUNLOCK(tp->t_inpcb);
536 TCPID_BUCKET_REF(tlb);
537 INP_WUNLOCK(tp->t_inpcb);
538 TCPID_BUCKET_LOCK(tlb);
539 strlcpy(tlb->tlb_tag, tag, TCP_LOG_TAG_LEN);
540 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
541 TCPID_BUCKET_UNLOCK(tlb);
543 if (tree_locked == TREE_WLOCKED) {
544 TCPID_TREE_WLOCK_ASSERT();
545 TCPID_TREE_WUNLOCK();
546 } else if (tree_locked == TREE_RLOCKED) {
547 TCPID_TREE_RLOCK_ASSERT();
548 TCPID_TREE_RUNLOCK();
550 TCPID_TREE_UNLOCK_ASSERT();
556 * Set the TCP log ID for a TCPCB.
557 * Called with INPCB locked. Returns with it unlocked.
560 tcp_log_set_id(struct tcpcb *tp, char *id)
562 struct tcp_log_id_bucket *tlb, *tmp_tlb;
563 struct tcp_log_id_node *tln;
571 tree_locked = TREE_UNLOCKED;
572 bucket_locked = false;
575 INP_WLOCK_ASSERT(inp);
577 /* See if the ID is unchanged. */
578 if ((tp->t_lib != NULL && !strcmp(tp->t_lib->tlb_id, id)) ||
579 (tp->t_lib == NULL && *id == 0)) {
580 if (tp->t_lib != NULL) {
581 tcp_log_increment_reqcnt(tp->t_lib);
582 if ((tp->t_lib->tlb_logstate) &&
583 (tp->t_log_state_set == 0)) {
584 /* Clone in any logging */
586 tp->t_logstate = tp->t_lib->tlb_logstate;
588 if ((tp->t_lib->tlb_loglimit) &&
589 (tp->t_log_state_set == 0)) {
590 /* We also have a limit set */
592 tp->t_loglimit = tp->t_lib->tlb_loglimit;
600 * If the TCPCB had a previous ID, we need to extricate it from
603 * Drop the TCPCB lock and lock the tree and the bucket.
604 * Because this is called in the socket context, we (theoretically)
605 * don't need to worry about the INPCB completely going away
608 if (tp->t_lib != NULL) {
610 TCPID_BUCKET_REF(tlb);
613 if (tree_locked == TREE_UNLOCKED) {
615 tree_locked = TREE_RLOCKED;
617 TCPID_BUCKET_LOCK(tlb);
618 bucket_locked = true;
622 * Unreference the bucket. If our bucket went away, it is no
623 * longer locked or valid.
625 if (tcp_log_unref_bucket(tlb, &tree_locked, inp)) {
626 bucket_locked = false;
630 /* Validate the INP. */
634 * Evaluate whether the bucket changed while we were unlocked.
636 * Possible scenarios here:
637 * 1. Bucket is unchanged and the same one we started with.
638 * 2. The TCPCB no longer has a bucket and our bucket was
640 * 3. The TCPCB has a new bucket, whether ours was freed.
641 * 4. The TCPCB no longer has a bucket and our bucket was
644 * In cases 2-4, we will start over. In case 1, we will
645 * proceed here to remove the bucket.
647 if (tlb == NULL || tp->t_lib != tlb) {
648 KASSERT(bucket_locked || tlb == NULL,
649 ("%s: bucket_locked (%d) and tlb (%p) are "
650 "inconsistent", __func__, bucket_locked, tlb));
653 TCPID_BUCKET_UNLOCK(tlb);
654 bucket_locked = false;
661 * Store the (struct tcp_log_id_node) for reuse. Then, remove
662 * it from the bucket. In the process, we may end up relocking.
663 * If so, we need to validate that the INP is still valid, and
664 * the TCPCB entries match we expect.
666 * We will clear tlb and change the bucket_locked state just
667 * before calling tcp_log_remove_id_node(), since that function
668 * will unlock the bucket.
671 uma_zfree(tcp_log_node_zone, tln);
674 bucket_locked = false;
675 if (tcp_log_remove_id_node(inp, tp, NULL, NULL, &tree_locked)) {
679 * If the TCPCB moved to a new bucket while we had
680 * dropped the lock, restart.
682 if (tp->t_lib != NULL || tp->t_lin != NULL)
687 * Yay! We successfully removed the TCPCB from its old
690 * On to bigger and better things...
694 /* At this point, the TCPCB should not be in any bucket. */
695 KASSERT(tp->t_lib == NULL, ("%s: tp->t_lib is not NULL", __func__));
698 * If the new ID is not empty, we need to now assign this TCPCB to a
702 /* Get a new tln, if we don't already have one to reuse. */
704 tln = uma_zalloc(tcp_log_node_zone, M_NOWAIT | M_ZERO);
714 * Drop the INP lock for a bit. We don't need it, and dropping
715 * it prevents lock order reversals.
719 /* Make sure we have at least a read lock on the tree. */
720 tcp_log_id_validate_tree_lock(tree_locked);
721 if (tree_locked == TREE_UNLOCKED) {
723 tree_locked = TREE_RLOCKED;
728 * Remember that we constructed (struct tcp_log_id_node) so
729 * we can safely cast the id to it for the purposes of finding.
731 KASSERT(tlb == NULL, ("%s:%d tlb unexpectedly non-NULL",
732 __func__, __LINE__));
733 tmp_tlb = RB_FIND(tcp_log_id_tree, &tcp_log_id_head,
734 (struct tcp_log_id_bucket *) id);
737 * If we didn't find a matching bucket, we need to add a new
738 * one. This requires a write lock. But, of course, we will
739 * need to recheck some things when we re-acquire the lock.
741 if (tmp_tlb == NULL && tree_locked != TREE_WLOCKED) {
742 tree_locked = TREE_WLOCKED;
743 if (!TCPID_TREE_UPGRADE()) {
744 TCPID_TREE_RUNLOCK();
748 * The tree may have changed while we were
755 /* If we need to add a new bucket, do it now. */
756 if (tmp_tlb == NULL) {
757 /* Allocate new bucket. */
758 tlb = uma_zalloc(tcp_log_bucket_zone, M_NOWAIT);
763 counter_u64_add(tcp_log_pcb_ids_cur, 1);
764 counter_u64_add(tcp_log_pcb_ids_tot, 1);
766 if ((tcp_log_auto_all == false) &&
768 tcp_log_selectauto()) {
769 /* Save off the log state */
770 tlb->tlb_logstate = tcp_log_auto_mode;
772 tlb->tlb_logstate = TCP_LOG_STATE_OFF;
773 tlb->tlb_loglimit = 0;
774 tlb->tlb_tag[0] = '\0'; /* Default to an empty tag. */
777 * Copy the ID to the bucket.
778 * NB: Don't use strlcpy() unless you are sure
779 * we've always validated NULL termination.
781 * TODO: When I'm done writing this, see if we
782 * we have correctly validated NULL termination and
783 * can use strlcpy(). :-)
785 strncpy(tlb->tlb_id, id, TCP_LOG_ID_LEN - 1);
786 tlb->tlb_id[TCP_LOG_ID_LEN - 1] = '\0';
789 * Take the refcount for the first node and go ahead
790 * and lock this. Note that we zero the tlb_mtx
791 * structure, since 0xdeadc0de flips the right bits
792 * for the code to think that this mutex has already
793 * been initialized. :-(
795 SLIST_INIT(&tlb->tlb_head);
796 refcount_init(&tlb->tlb_refcnt, 1);
798 memset(&tlb->tlb_mtx, 0, sizeof(struct mtx));
799 TCPID_BUCKET_LOCK_INIT(tlb);
800 TCPID_BUCKET_LOCK(tlb);
801 bucket_locked = true;
803 #define FREE_NEW_TLB() do { \
804 TCPID_BUCKET_LOCK_DESTROY(tlb); \
805 uma_zfree(tcp_log_bucket_zone, tlb); \
806 counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1); \
807 counter_u64_add(tcp_log_pcb_ids_tot, (int64_t)-1); \
808 bucket_locked = false; \
812 * Relock the INP and make sure we are still
816 RECHECK_INP_CLEAN(FREE_NEW_TLB());
817 if (tp->t_lib != NULL) {
822 /* Add the new bucket to the tree. */
823 tmp_tlb = RB_INSERT(tcp_log_id_tree, &tcp_log_id_head,
825 KASSERT(tmp_tlb == NULL,
826 ("%s: Unexpected conflicting bucket (%p) while "
827 "adding new bucket (%p)", __func__, tmp_tlb, tlb));
830 * If we found a conflicting bucket, free the new
831 * one we made and fall through to use the existing
834 if (tmp_tlb != NULL) {
841 /* If we found an existing bucket, use it. */
842 if (tmp_tlb != NULL) {
844 TCPID_BUCKET_LOCK(tlb);
845 bucket_locked = true;
848 * Relock the INP and make sure we are still
851 INP_UNLOCK_ASSERT(inp);
854 if (tp->t_lib != NULL) {
855 TCPID_BUCKET_UNLOCK(tlb);
856 bucket_locked = false;
861 /* Take a reference on the bucket. */
862 TCPID_BUCKET_REF(tlb);
864 /* Record the request. */
865 tcp_log_increment_reqcnt(tlb);
868 tcp_log_grow_tlb(tlb->tlb_id, tp);
870 /* Add the new node to the list. */
871 SLIST_INSERT_HEAD(&tlb->tlb_head, tln, tln_list);
874 if (tp->t_lib->tlb_logstate) {
875 /* Clone in any logging */
877 tp->t_logstate = tp->t_lib->tlb_logstate;
879 if (tp->t_lib->tlb_loglimit) {
880 /* The loglimit too */
882 tp->t_loglimit = tp->t_lib->tlb_loglimit;
890 /* Unlock things, as needed, and return. */
893 INP_UNLOCK_ASSERT(inp);
895 TCPID_BUCKET_LOCK_ASSERT(tlb);
896 TCPID_BUCKET_UNLOCK(tlb);
897 } else if (tlb != NULL)
898 TCPID_BUCKET_UNLOCK_ASSERT(tlb);
899 if (tree_locked == TREE_WLOCKED) {
900 TCPID_TREE_WLOCK_ASSERT();
901 TCPID_TREE_WUNLOCK();
902 } else if (tree_locked == TREE_RLOCKED) {
903 TCPID_TREE_RLOCK_ASSERT();
904 TCPID_TREE_RUNLOCK();
906 TCPID_TREE_UNLOCK_ASSERT();
908 uma_zfree(tcp_log_node_zone, tln);
913 * Get the TCP log ID for a TCPCB.
914 * Called with INPCB locked.
915 * 'buf' must point to a buffer that is at least TCP_LOG_ID_LEN bytes long.
916 * Returns number of bytes copied.
919 tcp_log_get_id(struct tcpcb *tp, char *buf)
923 INP_LOCK_ASSERT(tp->t_inpcb);
924 if (tp->t_lib != NULL) {
925 len = strlcpy(buf, tp->t_lib->tlb_id, TCP_LOG_ID_LEN);
926 KASSERT(len < TCP_LOG_ID_LEN,
927 ("%s:%d: tp->t_lib->tlb_id too long (%zu)",
928 __func__, __LINE__, len));
937 * Get the tag associated with the TCPCB's log ID.
938 * Called with INPCB locked. Returns with it unlocked.
939 * 'buf' must point to a buffer that is at least TCP_LOG_TAG_LEN bytes long.
940 * Returns number of bytes copied.
943 tcp_log_get_tag(struct tcpcb *tp, char *buf)
945 struct tcp_log_id_bucket *tlb;
949 INP_WLOCK_ASSERT(tp->t_inpcb);
951 tree_locked = TREE_UNLOCKED;
955 TCPID_BUCKET_REF(tlb);
956 INP_WUNLOCK(tp->t_inpcb);
957 TCPID_BUCKET_LOCK(tlb);
958 len = strlcpy(buf, tlb->tlb_tag, TCP_LOG_TAG_LEN);
959 KASSERT(len < TCP_LOG_TAG_LEN,
960 ("%s:%d: tp->t_lib->tlb_tag too long (%zu)",
961 __func__, __LINE__, len));
962 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
963 TCPID_BUCKET_UNLOCK(tlb);
965 if (tree_locked == TREE_WLOCKED) {
966 TCPID_TREE_WLOCK_ASSERT();
967 TCPID_TREE_WUNLOCK();
968 } else if (tree_locked == TREE_RLOCKED) {
969 TCPID_TREE_RLOCK_ASSERT();
970 TCPID_TREE_RUNLOCK();
972 TCPID_TREE_UNLOCK_ASSERT();
974 INP_WUNLOCK(tp->t_inpcb);
983 * Get number of connections with the same log ID.
984 * Log ID is taken from given TCPCB.
985 * Called with INPCB locked.
988 tcp_log_get_id_cnt(struct tcpcb *tp)
991 INP_WLOCK_ASSERT(tp->t_inpcb);
992 return ((tp->t_lib == NULL) ? 0 : tp->t_lib->tlb_refcnt);
995 #ifdef TCPLOG_DEBUG_RINGBUF
997 * Functions/macros to increment/decrement reference count for a log
998 * entry. This should catch when we do a double-free/double-remove or
1002 _tcp_log_entry_refcnt_add(struct tcp_log_mem *log_entry, const char *func,
1007 refcnt = atomic_fetchadd_int(&log_entry->tlm_refcnt, 1);
1009 panic("%s:%d: log_entry(%p)->tlm_refcnt is %d (expected 0)",
1010 func, line, log_entry, refcnt);
1012 #define tcp_log_entry_refcnt_add(l) \
1013 _tcp_log_entry_refcnt_add((l), __func__, __LINE__)
1016 _tcp_log_entry_refcnt_rem(struct tcp_log_mem *log_entry, const char *func,
1021 refcnt = atomic_fetchadd_int(&log_entry->tlm_refcnt, -1);
1023 panic("%s:%d: log_entry(%p)->tlm_refcnt is %d (expected 1)",
1024 func, line, log_entry, refcnt);
1026 #define tcp_log_entry_refcnt_rem(l) \
1027 _tcp_log_entry_refcnt_rem((l), __func__, __LINE__)
1029 #else /* !TCPLOG_DEBUG_RINGBUF */
1031 #define tcp_log_entry_refcnt_add(l)
1032 #define tcp_log_entry_refcnt_rem(l)
1037 * Cleanup after removing a log entry, but only decrement the count if we
1038 * are running INVARIANTS.
1041 tcp_log_free_log_common(struct tcp_log_mem *log_entry, int *count __unused)
1044 uma_zfree(tcp_log_zone, log_entry);
1047 KASSERT(*count >= 0,
1048 ("%s: count unexpectedly negative", __func__));
1053 tcp_log_free_entries(struct tcp_log_stailq *head, int *count)
1055 struct tcp_log_mem *log_entry;
1057 /* Free the entries. */
1058 while ((log_entry = STAILQ_FIRST(head)) != NULL) {
1059 STAILQ_REMOVE_HEAD(head, tlm_queue);
1060 tcp_log_entry_refcnt_rem(log_entry);
1061 tcp_log_free_log_common(log_entry, count);
1065 /* Cleanup after removing a log entry. */
1067 tcp_log_remove_log_cleanup(struct tcpcb *tp, struct tcp_log_mem *log_entry)
1069 uma_zfree(tcp_log_zone, log_entry);
1071 KASSERT(tp->t_lognum >= 0,
1072 ("%s: tp->t_lognum unexpectedly negative", __func__));
1075 /* Remove a log entry from the head of a list. */
1077 tcp_log_remove_log_head(struct tcpcb *tp, struct tcp_log_mem *log_entry)
1080 KASSERT(log_entry == STAILQ_FIRST(&tp->t_logs),
1081 ("%s: attempt to remove non-HEAD log entry", __func__));
1082 STAILQ_REMOVE_HEAD(&tp->t_logs, tlm_queue);
1083 tcp_log_entry_refcnt_rem(log_entry);
1084 tcp_log_remove_log_cleanup(tp, log_entry);
1087 #ifdef TCPLOG_DEBUG_RINGBUF
1089 * Initialize the log entry's reference count, which we want to
1090 * survive allocations.
1093 tcp_log_zone_init(void *mem, int size, int flags __unused)
1095 struct tcp_log_mem *tlm;
1097 KASSERT(size >= sizeof(struct tcp_log_mem),
1098 ("%s: unexpectedly short (%d) allocation", __func__, size));
1099 tlm = (struct tcp_log_mem *)mem;
1100 tlm->tlm_refcnt = 0;
1105 * Double check that the refcnt is zero on allocation and return.
1108 tcp_log_zone_ctor(void *mem, int size, void *args __unused, int flags __unused)
1110 struct tcp_log_mem *tlm;
1112 KASSERT(size >= sizeof(struct tcp_log_mem),
1113 ("%s: unexpectedly short (%d) allocation", __func__, size));
1114 tlm = (struct tcp_log_mem *)mem;
1115 if (tlm->tlm_refcnt != 0)
1116 panic("%s:%d: tlm(%p)->tlm_refcnt is %d (expected 0)",
1117 __func__, __LINE__, tlm, tlm->tlm_refcnt);
1122 tcp_log_zone_dtor(void *mem, int size, void *args __unused)
1124 struct tcp_log_mem *tlm;
1126 KASSERT(size >= sizeof(struct tcp_log_mem),
1127 ("%s: unexpectedly short (%d) allocation", __func__, size));
1128 tlm = (struct tcp_log_mem *)mem;
1129 if (tlm->tlm_refcnt != 0)
1130 panic("%s:%d: tlm(%p)->tlm_refcnt is %d (expected 0)",
1131 __func__, __LINE__, tlm, tlm->tlm_refcnt);
1133 #endif /* TCPLOG_DEBUG_RINGBUF */
1135 /* Do global initialization. */
1140 tcp_log_zone = uma_zcreate("tcp_log", sizeof(struct tcp_log_mem),
1141 #ifdef TCPLOG_DEBUG_RINGBUF
1142 tcp_log_zone_ctor, tcp_log_zone_dtor, tcp_log_zone_init,
1146 NULL, UMA_ALIGN_PTR, 0);
1147 (void)uma_zone_set_max(tcp_log_zone, TCP_LOG_BUF_DEFAULT_GLOBAL_LIMIT);
1148 tcp_log_bucket_zone = uma_zcreate("tcp_log_bucket",
1149 sizeof(struct tcp_log_id_bucket), NULL, NULL, NULL, NULL,
1151 tcp_log_node_zone = uma_zcreate("tcp_log_node",
1152 sizeof(struct tcp_log_id_node), NULL, NULL, NULL, NULL,
1154 #ifdef TCPLOG_DEBUG_COUNTERS
1155 tcp_log_queued = counter_u64_alloc(M_WAITOK);
1156 tcp_log_que_fail1 = counter_u64_alloc(M_WAITOK);
1157 tcp_log_que_fail2 = counter_u64_alloc(M_WAITOK);
1158 tcp_log_que_fail3 = counter_u64_alloc(M_WAITOK);
1159 tcp_log_que_fail4 = counter_u64_alloc(M_WAITOK);
1160 tcp_log_que_fail5 = counter_u64_alloc(M_WAITOK);
1161 tcp_log_que_copyout = counter_u64_alloc(M_WAITOK);
1162 tcp_log_que_read = counter_u64_alloc(M_WAITOK);
1163 tcp_log_que_freed = counter_u64_alloc(M_WAITOK);
1165 tcp_log_pcb_ids_cur = counter_u64_alloc(M_WAITOK);
1166 tcp_log_pcb_ids_tot = counter_u64_alloc(M_WAITOK);
1168 rw_init_flags(&tcp_id_tree_lock, "TCP ID tree", RW_NEW);
1169 mtx_init(&tcp_log_expireq_mtx, "TCP log expireq", NULL, MTX_DEF);
1170 callout_init(&tcp_log_expireq_callout, 1);
1173 /* Do per-TCPCB initialization. */
1175 tcp_log_tcpcbinit(struct tcpcb *tp)
1178 /* A new TCPCB should start out zero-initialized. */
1179 STAILQ_INIT(&tp->t_logs);
1182 * If we are doing auto-capturing, figure out whether we will capture
1185 tp->t_loglimit = tcp_log_session_limit;
1186 if ((tcp_log_auto_all == true) &&
1187 tcp_log_auto_mode &&
1188 tcp_log_selectauto()) {
1189 tp->t_logstate = tcp_log_auto_mode;
1190 tp->t_flags2 |= TF2_LOG_AUTO;
1195 /* Remove entries */
1197 tcp_log_expire(void *unused __unused)
1199 struct tcp_log_id_bucket *tlb;
1200 struct tcp_log_id_node *tln;
1201 sbintime_t expiry_limit;
1204 TCPLOG_EXPIREQ_LOCK();
1205 if (callout_pending(&tcp_log_expireq_callout)) {
1206 /* Callout was reset. */
1207 TCPLOG_EXPIREQ_UNLOCK();
1212 * Process entries until we reach one that expires too far in the
1213 * future. Look one second in the future.
1215 expiry_limit = getsbinuptime() + SBT_1S;
1216 tree_locked = TREE_UNLOCKED;
1218 while ((tln = STAILQ_FIRST(&tcp_log_expireq_head)) != NULL &&
1219 tln->tln_expiretime <= expiry_limit) {
1220 if (!callout_active(&tcp_log_expireq_callout)) {
1222 * Callout was stopped. I guess we should
1223 * just quit at this point.
1225 TCPLOG_EXPIREQ_UNLOCK();
1230 * Remove the node from the head of the list and unlock
1231 * the list. Change the expiry time to SBT_MAX as a signal
1232 * to other threads that we now own this.
1234 STAILQ_REMOVE_HEAD(&tcp_log_expireq_head, tln_expireq);
1235 tln->tln_expiretime = SBT_MAX;
1236 TCPLOG_EXPIREQ_UNLOCK();
1239 * Remove the node from the bucket.
1241 tlb = tln->tln_bucket;
1242 TCPID_BUCKET_LOCK(tlb);
1243 if (tcp_log_remove_id_node(NULL, NULL, tlb, tln, &tree_locked)) {
1244 tcp_log_id_validate_tree_lock(tree_locked);
1245 if (tree_locked == TREE_WLOCKED)
1246 TCPID_TREE_WUNLOCK();
1248 TCPID_TREE_RUNLOCK();
1249 tree_locked = TREE_UNLOCKED;
1252 /* Drop the INP reference. */
1253 INP_WLOCK(tln->tln_inp);
1254 if (!in_pcbrele_wlocked(tln->tln_inp))
1255 INP_WUNLOCK(tln->tln_inp);
1257 /* Free the log records. */
1258 tcp_log_free_entries(&tln->tln_entries, &tln->tln_count);
1260 /* Free the node. */
1261 uma_zfree(tcp_log_node_zone, tln);
1263 /* Relock the expiry queue. */
1264 TCPLOG_EXPIREQ_LOCK();
1268 * We've expired all the entries we can. Do we need to reschedule
1271 callout_deactivate(&tcp_log_expireq_callout);
1274 * Get max(now + TCP_LOG_EXPIRE_INTVL, tln->tln_expiretime) and
1275 * set the next callout to that. (This helps ensure we generally
1276 * run the callout no more often than desired.)
1278 expiry_limit = getsbinuptime() + TCP_LOG_EXPIRE_INTVL;
1279 if (expiry_limit < tln->tln_expiretime)
1280 expiry_limit = tln->tln_expiretime;
1281 callout_reset_sbt(&tcp_log_expireq_callout, expiry_limit,
1282 SBT_1S, tcp_log_expire, NULL, C_ABSOLUTE);
1286 TCPLOG_EXPIREQ_UNLOCK();
1291 * Move log data from the TCPCB to a new node. This will reset the TCPCB log
1292 * entries and log count; however, it will not touch other things from the
1293 * TCPCB (e.g. t_lin, t_lib).
1295 * NOTE: Must hold a lock on the INP.
1298 tcp_log_move_tp_to_node(struct tcpcb *tp, struct tcp_log_id_node *tln)
1301 INP_WLOCK_ASSERT(tp->t_inpcb);
1303 tln->tln_ie = tp->t_inpcb->inp_inc.inc_ie;
1304 if (tp->t_inpcb->inp_inc.inc_flags & INC_ISIPV6)
1305 tln->tln_af = AF_INET6;
1307 tln->tln_af = AF_INET;
1308 tln->tln_entries = tp->t_logs;
1309 tln->tln_count = tp->t_lognum;
1310 tln->tln_bucket = tp->t_lib;
1312 /* Clear information from the PCB. */
1313 STAILQ_INIT(&tp->t_logs);
1317 /* Do per-TCPCB cleanup */
1319 tcp_log_tcpcbfini(struct tcpcb *tp)
1321 struct tcp_log_id_node *tln, *tln_first;
1322 struct tcp_log_mem *log_entry;
1323 sbintime_t callouttime;
1325 INP_WLOCK_ASSERT(tp->t_inpcb);
1327 TCP_LOG_EVENT(tp, NULL, NULL, NULL, TCP_LOG_CONNEND, 0, 0, NULL, false);
1330 * If we were gathering packets to be automatically dumped, try to do
1331 * it now. If this succeeds, the log information in the TCPCB will be
1332 * cleared. Otherwise, we'll handle the log information as we do
1335 switch(tp->t_logstate) {
1336 case TCP_LOG_STATE_HEAD_AUTO:
1337 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from head",
1340 case TCP_LOG_STATE_TAIL_AUTO:
1341 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from tail",
1344 case TCP_LOG_STATE_CONTINUAL:
1345 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
1351 * There are two ways we could keep logs: per-socket or per-ID. If
1352 * we are tracking logs with an ID, then the logs survive the
1353 * destruction of the TCPCB.
1355 * If the TCPCB is associated with an ID node, move the logs from the
1356 * TCPCB to the ID node. In theory, this is safe, for reasons which I
1357 * will now explain for my own benefit when I next need to figure out
1360 * We own the INP lock. Therefore, no one else can change the contents
1361 * of this node (Rule C). Further, no one can remove this node from
1362 * the bucket while we hold the lock (Rule D). Basically, no one can
1363 * mess with this node. That leaves two states in which we could be:
1365 * 1. Another thread is currently waiting to acquire the INP lock, with
1366 * plans to do something with this node. When we drop the INP lock,
1367 * they will have a chance to do that. They will recheck the
1368 * tln_closed field (see note to Rule C) and then acquire the
1369 * bucket lock before proceeding further.
1371 * 2. Another thread will try to acquire a lock at some point in the
1372 * future. If they try to acquire a lock before we set the
1373 * tln_closed field, they will follow state #1. If they try to
1374 * acquire a lock after we set the tln_closed field, they will be
1375 * able to make changes to the node, at will, following Rule C.
1377 * Therefore, we currently own this node and can make any changes
1378 * we want. But, as soon as we set the tln_closed field to true, we
1379 * have effectively dropped our lock on the node. (For this reason, we
1380 * also need to make sure our writes are ordered correctly. An atomic
1381 * operation with "release" semantics should be sufficient.)
1384 if (tp->t_lin != NULL) {
1385 /* Copy the relevant information to the log entry. */
1387 KASSERT(tln->tln_inp == tp->t_inpcb,
1388 ("%s: Mismatched inp (tln->tln_inp=%p, tp->t_inpcb=%p)",
1389 __func__, tln->tln_inp, tp->t_inpcb));
1390 tcp_log_move_tp_to_node(tp, tln);
1392 /* Clear information from the PCB. */
1397 * Take a reference on the INP. This ensures that the INP
1398 * remains valid while the node is on the expiry queue. This
1399 * ensures the INP is valid for other threads that may be
1400 * racing to lock this node when we move it to the expire
1403 in_pcbref(tp->t_inpcb);
1406 * Store the entry on the expiry list. The exact behavior
1407 * depends on whether we have entries to keep. If so, we
1408 * put the entry at the tail of the list and expire in
1409 * TCP_LOG_EXPIRE_TIME. Otherwise, we expire "now" and put
1410 * the entry at the head of the list. (Handling the cleanup
1411 * via the expiry timer lets us avoid locking messy-ness here.)
1413 tln->tln_expiretime = getsbinuptime();
1414 TCPLOG_EXPIREQ_LOCK();
1415 if (tln->tln_count) {
1416 tln->tln_expiretime += TCP_LOG_EXPIRE_TIME;
1417 if (STAILQ_EMPTY(&tcp_log_expireq_head) &&
1418 !callout_active(&tcp_log_expireq_callout)) {
1420 * We are adding the first entry and a callout
1421 * is not currently scheduled; therefore, we
1422 * need to schedule one.
1424 callout_reset_sbt(&tcp_log_expireq_callout,
1425 tln->tln_expiretime, SBT_1S, tcp_log_expire,
1428 STAILQ_INSERT_TAIL(&tcp_log_expireq_head, tln,
1431 callouttime = tln->tln_expiretime +
1432 TCP_LOG_EXPIRE_INTVL;
1433 tln_first = STAILQ_FIRST(&tcp_log_expireq_head);
1435 if ((tln_first == NULL ||
1436 callouttime < tln_first->tln_expiretime) &&
1437 (callout_pending(&tcp_log_expireq_callout) ||
1438 !callout_active(&tcp_log_expireq_callout))) {
1440 * The list is empty, or we want to run the
1441 * expire code before the first entry's timer
1442 * fires. Also, we are in a case where a callout
1443 * is not actively running. We want to reset
1444 * the callout to occur sooner.
1446 callout_reset_sbt(&tcp_log_expireq_callout,
1447 callouttime, SBT_1S, tcp_log_expire, NULL,
1452 * Insert to the head, or just after the head, as
1453 * appropriate. (This might result in small
1454 * mis-orderings as a bunch of "expire now" entries
1455 * gather at the start of the list, but that should
1456 * not produce big problems, since the expire timer
1457 * will walk through all of them.)
1459 if (tln_first == NULL ||
1460 tln->tln_expiretime < tln_first->tln_expiretime)
1461 STAILQ_INSERT_HEAD(&tcp_log_expireq_head, tln,
1464 STAILQ_INSERT_AFTER(&tcp_log_expireq_head,
1465 tln_first, tln, tln_expireq);
1467 TCPLOG_EXPIREQ_UNLOCK();
1470 * We are done messing with the tln. After this point, we
1471 * can't touch it. (Note that the "release" semantics should
1472 * be included with the TCPLOG_EXPIREQ_UNLOCK() call above.
1473 * Therefore, they should be unnecessary here. However, it
1474 * seems like a good idea to include them anyway, since we
1475 * really are releasing a lock here.)
1477 atomic_store_rel_int(&tln->tln_closed, 1);
1479 /* Remove log entries. */
1480 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1481 tcp_log_remove_log_head(tp, log_entry);
1482 KASSERT(tp->t_lognum == 0,
1483 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
1484 __func__, tp->t_lognum));
1488 * Change the log state to off (just in case anything tries to sneak
1489 * in a last-minute log).
1491 tp->t_logstate = TCP_LOG_STATE_OFF;
1495 tcp_log_purge_tp_logbuf(struct tcpcb *tp)
1497 struct tcp_log_mem *log_entry;
1501 INP_WLOCK_ASSERT(inp);
1502 if (tp->t_lognum == 0)
1505 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1506 tcp_log_remove_log_head(tp, log_entry);
1507 KASSERT(tp->t_lognum == 0,
1508 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
1509 __func__, tp->t_lognum));
1510 tp->t_logstate = TCP_LOG_STATE_OFF;
1514 * This logs an event for a TCP socket. Normally, this is called via
1515 * TCP_LOG_EVENT or TCP_LOG_EVENT_VERBOSE. See the documentation for
1519 struct tcp_log_buffer *
1520 tcp_log_event_(struct tcpcb *tp, struct tcphdr *th, struct sockbuf *rxbuf,
1521 struct sockbuf *txbuf, uint8_t eventid, int errornum, uint32_t len,
1522 union tcp_log_stackspecific *stackinfo, int th_hostorder,
1523 const char *output_caller, const char *func, int line, const struct timeval *itv)
1525 struct tcp_log_mem *log_entry;
1526 struct tcp_log_buffer *log_buf;
1527 int attempt_count = 0;
1528 struct tcp_log_verbose *log_verbose;
1531 KASSERT((func == NULL && line == 0) || (func != NULL && line > 0),
1532 ("%s called with inconsistent func (%p) and line (%d) arguments",
1533 __func__, func, line));
1535 INP_WLOCK_ASSERT(tp->t_inpcb);
1536 if (tcp_disable_all_bb_logs) {
1538 * The global shutdown logging
1539 * switch has been thrown. Call
1540 * the purge function that frees
1541 * purges out the logs and
1542 * turns off logging.
1544 tcp_log_purge_tp_logbuf(tp);
1547 KASSERT(tp->t_logstate == TCP_LOG_STATE_HEAD ||
1548 tp->t_logstate == TCP_LOG_STATE_TAIL ||
1549 tp->t_logstate == TCP_LOG_STATE_CONTINUAL ||
1550 tp->t_logstate == TCP_LOG_STATE_HEAD_AUTO ||
1551 tp->t_logstate == TCP_LOG_STATE_TAIL_AUTO,
1552 ("%s called with unexpected tp->t_logstate (%d)", __func__,
1556 * Get the serial number. We do this early so it will
1557 * increment even if we end up skipping the log entry for some
1560 logsn = tp->t_logsn++;
1563 * Can we get a new log entry? If so, increment the lognum counter
1567 if (tp->t_lognum < tp->t_loglimit) {
1568 if ((log_entry = uma_zalloc(tcp_log_zone, M_NOWAIT)) != NULL)
1573 /* Do we need to try to reuse? */
1574 if (log_entry == NULL) {
1576 * Sacrifice auto-logged sessions without a log ID if
1577 * tcp_log_auto_all is false. (If they don't have a log
1578 * ID by now, it is probable that either they won't get one
1579 * or we are resource-constrained.)
1581 if (tp->t_lib == NULL && (tp->t_flags2 & TF2_LOG_AUTO) &&
1582 !tcp_log_auto_all) {
1583 if (tcp_log_state_change(tp, TCP_LOG_STATE_CLEAR)) {
1585 panic("%s:%d: tcp_log_state_change() failed "
1586 "to set tp %p to TCP_LOG_STATE_CLEAR",
1587 __func__, __LINE__, tp);
1589 tp->t_logstate = TCP_LOG_STATE_OFF;
1594 * If we are in TCP_LOG_STATE_HEAD_AUTO state, try to dump
1595 * the buffers. If successful, deactivate tracing. Otherwise,
1596 * leave it active so we will retry.
1598 if (tp->t_logstate == TCP_LOG_STATE_HEAD_AUTO &&
1599 !tcp_log_dump_tp_logbuf(tp, "auto-dumped from head",
1601 tp->t_logstate = TCP_LOG_STATE_OFF;
1603 } else if ((tp->t_logstate == TCP_LOG_STATE_CONTINUAL) &&
1604 !tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
1606 if (attempt_count == 0) {
1610 #ifdef TCPLOG_DEBUG_COUNTERS
1611 counter_u64_add(tcp_log_que_fail4, 1);
1614 } else if (tp->t_logstate == TCP_LOG_STATE_HEAD_AUTO)
1617 /* If in HEAD state, just deactivate the tracing and return. */
1618 if (tp->t_logstate == TCP_LOG_STATE_HEAD) {
1619 tp->t_logstate = TCP_LOG_STATE_OFF;
1624 * Get a buffer to reuse. If that fails, just give up.
1625 * (We can't log anything without a buffer in which to
1628 * Note that we don't change the t_lognum counter
1629 * here. Because we are re-using the buffer, the total
1630 * number won't change.
1632 if ((log_entry = STAILQ_FIRST(&tp->t_logs)) == NULL)
1634 STAILQ_REMOVE_HEAD(&tp->t_logs, tlm_queue);
1635 tcp_log_entry_refcnt_rem(log_entry);
1638 KASSERT(log_entry != NULL,
1639 ("%s: log_entry unexpectedly NULL", __func__));
1641 /* Extract the log buffer and verbose buffer pointers. */
1642 log_buf = &log_entry->tlm_buf;
1643 log_verbose = &log_entry->tlm_v;
1645 /* Basic entries. */
1647 getmicrouptime(&log_buf->tlb_tv);
1649 memcpy(&log_buf->tlb_tv, itv, sizeof(struct timeval));
1650 log_buf->tlb_ticks = ticks;
1651 log_buf->tlb_sn = logsn;
1652 log_buf->tlb_stackid = tp->t_fb->tfb_id;
1653 log_buf->tlb_eventid = eventid;
1654 log_buf->tlb_eventflags = 0;
1655 log_buf->tlb_errno = errornum;
1657 /* Socket buffers */
1658 if (rxbuf != NULL) {
1659 log_buf->tlb_eventflags |= TLB_FLAG_RXBUF;
1660 log_buf->tlb_rxbuf.tls_sb_acc = rxbuf->sb_acc;
1661 log_buf->tlb_rxbuf.tls_sb_ccc = rxbuf->sb_ccc;
1662 log_buf->tlb_rxbuf.tls_sb_spare = 0;
1664 if (txbuf != NULL) {
1665 log_buf->tlb_eventflags |= TLB_FLAG_TXBUF;
1666 log_buf->tlb_txbuf.tls_sb_acc = txbuf->sb_acc;
1667 log_buf->tlb_txbuf.tls_sb_ccc = txbuf->sb_ccc;
1668 log_buf->tlb_txbuf.tls_sb_spare = 0;
1670 /* Copy values from tp to the log entry. */
1671 #define COPY_STAT(f) log_buf->tlb_ ## f = tp->f
1672 #define COPY_STAT_T(f) log_buf->tlb_ ## f = tp->t_ ## f
1674 COPY_STAT_T(starttime);
1679 COPY_STAT(snd_cwnd);
1681 COPY_STAT(snd_recover);
1683 COPY_STAT(snd_ssthresh);
1685 COPY_STAT_T(rttvar);
1690 COPY_STAT_T(dupacks);
1691 COPY_STAT_T(segqlen);
1692 COPY_STAT(snd_numholes);
1693 COPY_STAT(snd_scale);
1694 COPY_STAT(rcv_scale);
1697 log_buf->tlb_flex1 = 0;
1698 log_buf->tlb_flex2 = 0;
1699 /* Copy stack-specific info. */
1700 if (stackinfo != NULL) {
1701 memcpy(&log_buf->tlb_stackinfo, stackinfo,
1702 sizeof(log_buf->tlb_stackinfo));
1703 log_buf->tlb_eventflags |= TLB_FLAG_STACKINFO;
1707 log_buf->tlb_len = len;
1711 log_buf->tlb_eventflags |= TLB_FLAG_HDR;
1712 log_buf->tlb_th = *th;
1714 tcp_fields_to_net(&log_buf->tlb_th);
1715 optlen = (th->th_off << 2) - sizeof (struct tcphdr);
1717 memcpy(log_buf->tlb_opts, th + 1, optlen);
1720 /* Verbose information */
1722 log_buf->tlb_eventflags |= TLB_FLAG_VERBOSE;
1723 if (output_caller != NULL)
1724 strlcpy(log_verbose->tlv_snd_frm, output_caller,
1727 *log_verbose->tlv_snd_frm = 0;
1728 strlcpy(log_verbose->tlv_trace_func, func, TCP_FUNC_LEN);
1729 log_verbose->tlv_trace_line = line;
1732 /* Insert the new log at the tail. */
1733 STAILQ_INSERT_TAIL(&tp->t_logs, log_entry, tlm_queue);
1734 tcp_log_entry_refcnt_add(log_entry);
1739 * Change the logging state for a TCPCB. Returns 0 on success or an
1740 * error code on failure.
1743 tcp_log_state_change(struct tcpcb *tp, int state)
1745 struct tcp_log_mem *log_entry;
1747 INP_WLOCK_ASSERT(tp->t_inpcb);
1749 case TCP_LOG_STATE_CLEAR:
1750 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1751 tcp_log_remove_log_head(tp, log_entry);
1754 case TCP_LOG_STATE_OFF:
1755 tp->t_logstate = TCP_LOG_STATE_OFF;
1758 case TCP_LOG_STATE_TAIL:
1759 case TCP_LOG_STATE_HEAD:
1760 case TCP_LOG_STATE_CONTINUAL:
1761 case TCP_LOG_STATE_HEAD_AUTO:
1762 case TCP_LOG_STATE_TAIL_AUTO:
1763 tp->t_logstate = state;
1769 if (tcp_disable_all_bb_logs) {
1770 /* We are prohibited from doing any logs */
1771 tp->t_logstate = TCP_LOG_STATE_OFF;
1773 tp->t_flags2 &= ~(TF2_LOG_AUTO);
1778 /* If tcp_drain() is called, flush half the log entries. */
1780 tcp_log_drain(struct tcpcb *tp)
1782 struct tcp_log_mem *log_entry, *next;
1785 INP_WLOCK_ASSERT(tp->t_inpcb);
1786 if ((target = tp->t_lognum / 2) == 0)
1790 * If we are logging the "head" packets, we want to discard
1791 * from the tail of the queue. Otherwise, we want to discard
1794 if (tp->t_logstate == TCP_LOG_STATE_HEAD ||
1795 tp->t_logstate == TCP_LOG_STATE_HEAD_AUTO) {
1796 skip = tp->t_lognum - target;
1797 STAILQ_FOREACH(log_entry, &tp->t_logs, tlm_queue)
1800 KASSERT(log_entry != NULL,
1801 ("%s: skipped through all entries!", __func__));
1802 if (log_entry == NULL)
1804 while ((next = STAILQ_NEXT(log_entry, tlm_queue)) != NULL) {
1805 STAILQ_REMOVE_AFTER(&tp->t_logs, log_entry, tlm_queue);
1806 tcp_log_entry_refcnt_rem(next);
1807 tcp_log_remove_log_cleanup(tp, next);
1812 KASSERT(target == 0,
1813 ("%s: After removing from tail, target was %d", __func__,
1815 } else if (tp->t_logstate == TCP_LOG_STATE_CONTINUAL) {
1816 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
1819 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL &&
1821 tcp_log_remove_log_head(tp, log_entry);
1822 KASSERT(target <= 0,
1823 ("%s: After removing from head, target was %d", __func__,
1825 KASSERT(tp->t_lognum > 0,
1826 ("%s: After removing from head, tp->t_lognum was %d",
1828 KASSERT(log_entry != NULL,
1829 ("%s: After removing from head, the tailq was empty",
1835 tcp_log_copyout(struct sockopt *sopt, void *src, void *dst, size_t len)
1838 if (sopt->sopt_td != NULL)
1839 return (copyout(src, dst, len));
1840 bcopy(src, dst, len);
1845 tcp_log_logs_to_buf(struct sockopt *sopt, struct tcp_log_stailq *log_tailqp,
1846 struct tcp_log_buffer **end, int count)
1848 struct tcp_log_buffer *out_entry;
1849 struct tcp_log_mem *log_entry;
1853 int orig_count = count;
1856 /* Copy the data out. */
1858 out_entry = (struct tcp_log_buffer *) sopt->sopt_val;
1859 STAILQ_FOREACH(log_entry, log_tailqp, tlm_queue) {
1862 ("%s:%d: Exceeded expected count (%d) processing list %p",
1863 __func__, __LINE__, orig_count, log_tailqp));
1865 #ifdef TCPLOG_DEBUG_COUNTERS
1866 counter_u64_add(tcp_log_que_copyout, 1);
1870 * Skip copying out the header if it isn't present.
1871 * Instead, copy out zeros (to ensure we don't leak info).
1872 * TODO: Make sure we truly do zero everything we don't
1875 if (log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_HDR)
1876 entrysize = sizeof(struct tcp_log_buffer);
1878 entrysize = offsetof(struct tcp_log_buffer, tlb_th);
1879 error = tcp_log_copyout(sopt, &log_entry->tlm_buf, out_entry,
1883 if (!(log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_HDR)) {
1884 error = tcp_log_copyout(sopt, zerobuf,
1885 ((uint8_t *)out_entry) + entrysize,
1886 sizeof(struct tcp_log_buffer) - entrysize);
1890 * Copy out the verbose bit, if needed. Either way,
1891 * increment the output pointer the correct amount.
1893 if (log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_VERBOSE) {
1894 error = tcp_log_copyout(sopt, &log_entry->tlm_v,
1895 out_entry->tlb_verbose,
1896 sizeof(struct tcp_log_verbose));
1899 out_entry = (struct tcp_log_buffer *)
1900 (((uint8_t *) (out_entry + 1)) +
1901 sizeof(struct tcp_log_verbose));
1906 KASSERT(error || count == 0,
1907 ("%s:%d: Less than expected count (%d) processing list %p"
1908 " (%d remain)", __func__, __LINE__, orig_count,
1909 log_tailqp, count));
1915 * Copy out the buffer. Note that we do incremental copying, so
1916 * sooptcopyout() won't work. However, the goal is to produce the same
1917 * end result as if we copied in the entire user buffer, updated it,
1918 * and then used sooptcopyout() to copy it out.
1920 * NOTE: This should be called with a write lock on the PCB; however,
1921 * the function will drop it after it extracts the data from the TCPCB.
1924 tcp_log_getlogbuf(struct sockopt *sopt, struct tcpcb *tp)
1926 struct tcp_log_stailq log_tailq;
1927 struct tcp_log_mem *log_entry, *log_next;
1928 struct tcp_log_buffer *out_entry;
1930 size_t outsize, entrysize;
1933 INP_WLOCK_ASSERT(tp->t_inpcb);
1937 * Determine which log entries will fit in the buffer. As an
1938 * optimization, skip this if all the entries will clearly fit
1939 * in the buffer. (However, get an exact size if we are using
1943 if (sopt->sopt_valsize / (sizeof(struct tcp_log_buffer) +
1944 sizeof(struct tcp_log_verbose)) >= tp->t_lognum) {
1945 log_entry = STAILQ_LAST(&tp->t_logs, tcp_log_mem, tlm_queue);
1948 outnum = tp->t_lognum;
1951 outsize = outnum = 0;
1953 STAILQ_FOREACH(log_next, &tp->t_logs, tlm_queue) {
1954 entrysize = sizeof(struct tcp_log_buffer);
1955 if (log_next->tlm_buf.tlb_eventflags &
1957 entrysize += sizeof(struct tcp_log_verbose);
1958 if ((sopt->sopt_valsize - outsize) < entrysize)
1960 outsize += entrysize;
1962 log_entry = log_next;
1964 KASSERT(outsize <= sopt->sopt_valsize,
1965 ("%s: calculated output size (%zu) greater than available"
1966 "space (%zu)", __func__, outsize, sopt->sopt_valsize));
1972 * Copy traditional sooptcopyout() behavior: if sopt->sopt_val
1973 * is NULL, silently skip the copy. However, in this case, we
1974 * will leave the list alone and return. Functionally, this
1975 * gives userspace a way to poll for an approximate buffer
1976 * size they will need to get the log entries.
1978 if (sopt->sopt_val == NULL) {
1981 outsize = outnum * (sizeof(struct tcp_log_buffer) +
1982 sizeof(struct tcp_log_verbose));
1984 if (sopt->sopt_valsize > outsize)
1985 sopt->sopt_valsize = outsize;
1990 * Break apart the list. We'll save the ones we want to copy
1991 * out locally and remove them from the TCPCB list. We can
1992 * then drop the INPCB lock while we do the copyout.
1994 * There are roughly three cases:
1995 * 1. There was nothing to copy out. That's easy: drop the
1997 * 2. We are copying out the entire list. Again, that's easy:
1998 * move the whole list.
1999 * 3. We are copying out a partial list. That's harder. We
2000 * need to update the list book-keeping entries.
2002 if (log_entry != NULL && log_next == NULL) {
2003 /* Move entire list. */
2004 KASSERT(outnum == tp->t_lognum,
2005 ("%s:%d: outnum (%d) should match tp->t_lognum (%d)",
2006 __func__, __LINE__, outnum, tp->t_lognum));
2007 log_tailq = tp->t_logs;
2009 STAILQ_INIT(&tp->t_logs);
2010 } else if (log_entry != NULL) {
2011 /* Move partial list. */
2012 KASSERT(outnum < tp->t_lognum,
2013 ("%s:%d: outnum (%d) not less than tp->t_lognum (%d)",
2014 __func__, __LINE__, outnum, tp->t_lognum));
2015 STAILQ_FIRST(&log_tailq) = STAILQ_FIRST(&tp->t_logs);
2016 STAILQ_FIRST(&tp->t_logs) = STAILQ_NEXT(log_entry, tlm_queue);
2017 KASSERT(STAILQ_NEXT(log_entry, tlm_queue) != NULL,
2018 ("%s:%d: tp->t_logs is unexpectedly shorter than expected"
2019 "(tp: %p, log_tailq: %p, outnum: %d, tp->t_lognum: %d)",
2020 __func__, __LINE__, tp, &log_tailq, outnum, tp->t_lognum));
2021 STAILQ_NEXT(log_entry, tlm_queue) = NULL;
2022 log_tailq.stqh_last = &STAILQ_NEXT(log_entry, tlm_queue);
2023 tp->t_lognum -= outnum;
2025 STAILQ_INIT(&log_tailq);
2027 /* Drop the PCB lock. */
2030 /* Copy the data out. */
2031 error = tcp_log_logs_to_buf(sopt, &log_tailq, &out_entry, outnum);
2036 if ((inp->inp_flags & (INP_TIMEWAIT | INP_DROPPED)) == 0) {
2037 tp = intotcpcb(inp);
2039 /* Merge the two lists. */
2040 STAILQ_CONCAT(&log_tailq, &tp->t_logs);
2041 tp->t_logs = log_tailq;
2042 tp->t_lognum += outnum;
2046 /* Sanity check entries */
2047 KASSERT(((caddr_t)out_entry - (caddr_t)sopt->sopt_val) ==
2048 outsize, ("%s: Actual output size (%zu) != "
2049 "calculated output size (%zu)", __func__,
2050 (size_t)((caddr_t)out_entry - (caddr_t)sopt->sopt_val),
2053 /* Free the entries we just copied out. */
2054 STAILQ_FOREACH_SAFE(log_entry, &log_tailq, tlm_queue, log_next) {
2055 tcp_log_entry_refcnt_rem(log_entry);
2056 uma_zfree(tcp_log_zone, log_entry);
2060 sopt->sopt_valsize = (size_t)((caddr_t)out_entry -
2061 (caddr_t)sopt->sopt_val);
2066 tcp_log_free_queue(struct tcp_log_dev_queue *param)
2068 struct tcp_log_dev_log_queue *entry;
2070 KASSERT(param != NULL, ("%s: called with NULL param", __func__));
2074 entry = (struct tcp_log_dev_log_queue *)param;
2076 /* Free the entries. */
2077 tcp_log_free_entries(&entry->tldl_entries, &entry->tldl_count);
2079 /* Free the buffer, if it is allocated. */
2080 if (entry->tldl_common.tldq_buf != NULL)
2081 free(entry->tldl_common.tldq_buf, M_TCPLOGDEV);
2083 /* Free the queue entry. */
2084 free(entry, M_TCPLOGDEV);
2087 static struct tcp_log_common_header *
2088 tcp_log_expandlogbuf(struct tcp_log_dev_queue *param)
2090 struct tcp_log_dev_log_queue *entry;
2091 struct tcp_log_header *hdr;
2093 struct sockopt sopt;
2096 entry = (struct tcp_log_dev_log_queue *)param;
2098 /* Take a worst-case guess at space needs. */
2099 sopt.sopt_valsize = sizeof(struct tcp_log_header) +
2100 entry->tldl_count * (sizeof(struct tcp_log_buffer) +
2101 sizeof(struct tcp_log_verbose));
2102 hdr = malloc(sopt.sopt_valsize, M_TCPLOGDEV, M_NOWAIT);
2104 #ifdef TCPLOG_DEBUG_COUNTERS
2105 counter_u64_add(tcp_log_que_fail5, entry->tldl_count);
2109 sopt.sopt_val = hdr + 1;
2110 sopt.sopt_valsize -= sizeof(struct tcp_log_header);
2111 sopt.sopt_td = NULL;
2113 error = tcp_log_logs_to_buf(&sopt, &entry->tldl_entries,
2114 (struct tcp_log_buffer **)&end, entry->tldl_count);
2116 free(hdr, M_TCPLOGDEV);
2120 /* Free the entries. */
2121 tcp_log_free_entries(&entry->tldl_entries, &entry->tldl_count);
2122 entry->tldl_count = 0;
2124 memset(hdr, 0, sizeof(struct tcp_log_header));
2125 hdr->tlh_version = TCP_LOG_BUF_VER;
2126 hdr->tlh_type = TCP_LOG_DEV_TYPE_BBR;
2127 hdr->tlh_length = end - (uint8_t *)hdr;
2128 hdr->tlh_ie = entry->tldl_ie;
2129 hdr->tlh_af = entry->tldl_af;
2130 getboottime(&hdr->tlh_offset);
2131 strlcpy(hdr->tlh_id, entry->tldl_id, TCP_LOG_ID_LEN);
2132 strlcpy(hdr->tlh_tag, entry->tldl_tag, TCP_LOG_TAG_LEN);
2133 strlcpy(hdr->tlh_reason, entry->tldl_reason, TCP_LOG_REASON_LEN);
2134 return ((struct tcp_log_common_header *)hdr);
2138 * Queue the tcpcb's log buffer for transmission via the log buffer facility.
2140 * NOTE: This should be called with a write lock on the PCB.
2142 * how should be M_WAITOK or M_NOWAIT. If M_WAITOK, the function will drop
2143 * and reacquire the INP lock if it needs to do so.
2145 * If force is false, this will only dump auto-logged sessions if
2146 * tcp_log_auto_all is true or if there is a log ID defined for the session.
2149 tcp_log_dump_tp_logbuf(struct tcpcb *tp, char *reason, int how, bool force)
2151 struct tcp_log_dev_log_queue *entry;
2153 #ifdef TCPLOG_DEBUG_COUNTERS
2158 INP_WLOCK_ASSERT(inp);
2160 /* If there are no log entries, there is nothing to do. */
2161 if (tp->t_lognum == 0)
2164 /* Check for a log ID. */
2165 if (tp->t_lib == NULL && (tp->t_flags2 & TF2_LOG_AUTO) &&
2166 !tcp_log_auto_all && !force) {
2167 struct tcp_log_mem *log_entry;
2170 * We needed a log ID and none was found. Free the log entries
2171 * and return success. Also, cancel further logging. If the
2172 * session doesn't have a log ID by now, we'll assume it isn't
2175 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
2176 tcp_log_remove_log_head(tp, log_entry);
2177 KASSERT(tp->t_lognum == 0,
2178 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
2179 __func__, tp->t_lognum));
2180 tp->t_logstate = TCP_LOG_STATE_OFF;
2185 * Allocate memory. If we must wait, we'll need to drop the locks
2186 * and reacquire them (and do all the related business that goes
2189 entry = malloc(sizeof(struct tcp_log_dev_log_queue), M_TCPLOGDEV,
2191 if (entry == NULL && (how & M_NOWAIT)) {
2192 #ifdef TCPLOG_DEBUG_COUNTERS
2193 counter_u64_add(tcp_log_que_fail3, 1);
2197 if (entry == NULL) {
2199 entry = malloc(sizeof(struct tcp_log_dev_log_queue),
2200 M_TCPLOGDEV, M_WAITOK);
2203 * Note that this check is slightly overly-restrictive in
2204 * that the TCB can survive either of these events.
2205 * However, there is currently not a good way to ensure
2206 * that is the case. So, if we hit this M_WAIT path, we
2207 * may end up dropping some entries. That seems like a
2208 * small price to pay for safety.
2210 if (inp->inp_flags & (INP_TIMEWAIT | INP_DROPPED)) {
2211 free(entry, M_TCPLOGDEV);
2212 #ifdef TCPLOG_DEBUG_COUNTERS
2213 counter_u64_add(tcp_log_que_fail2, 1);
2215 return (ECONNRESET);
2217 tp = intotcpcb(inp);
2218 if (tp->t_lognum == 0) {
2219 free(entry, M_TCPLOGDEV);
2224 /* Fill in the unique parts of the queue entry. */
2225 if (tp->t_lib != NULL) {
2226 strlcpy(entry->tldl_id, tp->t_lib->tlb_id, TCP_LOG_ID_LEN);
2227 strlcpy(entry->tldl_tag, tp->t_lib->tlb_tag, TCP_LOG_TAG_LEN);
2229 strlcpy(entry->tldl_id, "UNKNOWN", TCP_LOG_ID_LEN);
2230 strlcpy(entry->tldl_tag, "UNKNOWN", TCP_LOG_TAG_LEN);
2233 strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN);
2235 strlcpy(entry->tldl_reason, "UNKNOWN", TCP_LOG_ID_LEN);
2236 entry->tldl_ie = inp->inp_inc.inc_ie;
2237 if (inp->inp_inc.inc_flags & INC_ISIPV6)
2238 entry->tldl_af = AF_INET6;
2240 entry->tldl_af = AF_INET;
2241 entry->tldl_entries = tp->t_logs;
2242 entry->tldl_count = tp->t_lognum;
2244 /* Fill in the common parts of the queue entry. */
2245 entry->tldl_common.tldq_buf = NULL;
2246 entry->tldl_common.tldq_xform = tcp_log_expandlogbuf;
2247 entry->tldl_common.tldq_dtor = tcp_log_free_queue;
2249 /* Clear the log data from the TCPCB. */
2250 #ifdef TCPLOG_DEBUG_COUNTERS
2251 num_entries = tp->t_lognum;
2254 STAILQ_INIT(&tp->t_logs);
2256 /* Add the entry. If no one is listening, free the entry. */
2257 if (tcp_log_dev_add_log((struct tcp_log_dev_queue *)entry)) {
2258 tcp_log_free_queue((struct tcp_log_dev_queue *)entry);
2259 #ifdef TCPLOG_DEBUG_COUNTERS
2260 counter_u64_add(tcp_log_que_fail1, num_entries);
2262 counter_u64_add(tcp_log_queued, num_entries);
2269 * Queue the log_id_node's log buffers for transmission via the log buffer
2272 * NOTE: This should be called with the bucket locked and referenced.
2274 * how should be M_WAITOK or M_NOWAIT. If M_WAITOK, the function will drop
2275 * and reacquire the bucket lock if it needs to do so. (The caller must
2276 * ensure that the tln is no longer on any lists so no one else will mess
2277 * with this while the lock is dropped!)
2280 tcp_log_dump_node_logbuf(struct tcp_log_id_node *tln, char *reason, int how)
2282 struct tcp_log_dev_log_queue *entry;
2283 struct tcp_log_id_bucket *tlb;
2285 tlb = tln->tln_bucket;
2286 TCPID_BUCKET_LOCK_ASSERT(tlb);
2287 KASSERT(tlb->tlb_refcnt > 0,
2288 ("%s:%d: Called with unreferenced bucket (tln=%p, tlb=%p)",
2289 __func__, __LINE__, tln, tlb));
2290 KASSERT(tln->tln_closed,
2291 ("%s:%d: Called for node with tln_closed==false (tln=%p)",
2292 __func__, __LINE__, tln));
2294 /* If there are no log entries, there is nothing to do. */
2295 if (tln->tln_count == 0)
2299 * Allocate memory. If we must wait, we'll need to drop the locks
2300 * and reacquire them (and do all the related business that goes
2303 entry = malloc(sizeof(struct tcp_log_dev_log_queue), M_TCPLOGDEV,
2305 if (entry == NULL && (how & M_NOWAIT))
2307 if (entry == NULL) {
2308 TCPID_BUCKET_UNLOCK(tlb);
2309 entry = malloc(sizeof(struct tcp_log_dev_log_queue),
2310 M_TCPLOGDEV, M_WAITOK);
2311 TCPID_BUCKET_LOCK(tlb);
2314 /* Fill in the common parts of the queue entry.. */
2315 entry->tldl_common.tldq_buf = NULL;
2316 entry->tldl_common.tldq_xform = tcp_log_expandlogbuf;
2317 entry->tldl_common.tldq_dtor = tcp_log_free_queue;
2319 /* Fill in the unique parts of the queue entry. */
2320 strlcpy(entry->tldl_id, tlb->tlb_id, TCP_LOG_ID_LEN);
2321 strlcpy(entry->tldl_tag, tlb->tlb_tag, TCP_LOG_TAG_LEN);
2323 strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN);
2325 strlcpy(entry->tldl_reason, "UNKNOWN", TCP_LOG_ID_LEN);
2326 entry->tldl_ie = tln->tln_ie;
2327 entry->tldl_entries = tln->tln_entries;
2328 entry->tldl_count = tln->tln_count;
2329 entry->tldl_af = tln->tln_af;
2331 /* Add the entry. If no one is listening, free the entry. */
2332 if (tcp_log_dev_add_log((struct tcp_log_dev_queue *)entry))
2333 tcp_log_free_queue((struct tcp_log_dev_queue *)entry);
2340 * Queue the log buffers for all sessions in a bucket for transmissions via
2341 * the log buffer facility.
2343 * NOTE: This should be called with a locked bucket; however, the function
2344 * will drop the lock.
2346 #define LOCAL_SAVE 10
2348 tcp_log_dumpbucketlogs(struct tcp_log_id_bucket *tlb, char *reason)
2350 struct tcp_log_id_node local_entries[LOCAL_SAVE];
2353 struct tcp_log_id_node *cur_tln, *prev_tln, *tmp_tln;
2354 int i, num_local_entries, tree_locked;
2355 bool expireq_locked;
2357 TCPID_BUCKET_LOCK_ASSERT(tlb);
2360 * Take a reference on the bucket to keep it from disappearing until
2363 TCPID_BUCKET_REF(tlb);
2366 * We'll try to create these without dropping locks. However, we
2367 * might very well need to drop locks to get memory. If that's the
2368 * case, we'll save up to 10 on the stack, and sacrifice the rest.
2369 * (Otherwise, we need to worry about finding our place again in a
2370 * potentially changed list. It just doesn't seem worth the trouble
2373 expireq_locked = false;
2374 num_local_entries = 0;
2376 tree_locked = TREE_UNLOCKED;
2377 SLIST_FOREACH_SAFE(cur_tln, &tlb->tlb_head, tln_list, tmp_tln) {
2379 * If this isn't associated with a TCPCB, we can pull it off
2380 * the list now. We need to be careful that the expire timer
2381 * hasn't already taken ownership (tln_expiretime == SBT_MAX).
2382 * If so, we let the expire timer code free the data.
2384 if (cur_tln->tln_closed) {
2387 * Get the expireq lock so we can get a consistent
2388 * read of tln_expiretime and so we can remove this
2391 if (!expireq_locked) {
2392 TCPLOG_EXPIREQ_LOCK();
2393 expireq_locked = true;
2397 * We ignore entries with tln_expiretime == SBT_MAX.
2398 * The expire timer code already owns those.
2400 KASSERT(cur_tln->tln_expiretime > (sbintime_t) 0,
2401 ("%s:%d: node on the expire queue without positive "
2402 "expire time", __func__, __LINE__));
2403 if (cur_tln->tln_expiretime == SBT_MAX) {
2408 /* Remove the entry from the expireq. */
2409 STAILQ_REMOVE(&tcp_log_expireq_head, cur_tln,
2410 tcp_log_id_node, tln_expireq);
2412 /* Remove the entry from the bucket. */
2413 if (prev_tln != NULL)
2414 SLIST_REMOVE_AFTER(prev_tln, tln_list);
2416 SLIST_REMOVE_HEAD(&tlb->tlb_head, tln_list);
2419 * Drop the INP and bucket reference counts. Due to
2420 * lock-ordering rules, we need to drop the expire
2423 TCPLOG_EXPIREQ_UNLOCK();
2424 expireq_locked = false;
2426 /* Drop the INP reference. */
2427 INP_WLOCK(cur_tln->tln_inp);
2428 if (!in_pcbrele_wlocked(cur_tln->tln_inp))
2429 INP_WUNLOCK(cur_tln->tln_inp);
2431 if (tcp_log_unref_bucket(tlb, &tree_locked, NULL)) {
2433 panic("%s: Bucket refcount unexpectedly 0.",
2437 * Recover as best we can: free the entry we
2440 tcp_log_free_entries(&cur_tln->tln_entries,
2441 &cur_tln->tln_count);
2442 uma_zfree(tcp_log_node_zone, cur_tln);
2446 if (tcp_log_dump_node_logbuf(cur_tln, reason,
2449 * If we have sapce, save the entries locally.
2450 * Otherwise, free them.
2452 if (num_local_entries < LOCAL_SAVE) {
2453 local_entries[num_local_entries] =
2455 num_local_entries++;
2457 tcp_log_free_entries(
2458 &cur_tln->tln_entries,
2459 &cur_tln->tln_count);
2463 /* No matter what, we are done with the node now. */
2464 uma_zfree(tcp_log_node_zone, cur_tln);
2467 * Because we removed this entry from the list, prev_tln
2468 * (which tracks the previous entry still on the tlb
2469 * list) remains unchanged.
2475 * If we get to this point, the session data is still held in
2476 * the TCPCB. So, we need to pull the data out of that.
2478 * We will need to drop the expireq lock so we can lock the INP.
2479 * We can then try to extract the data the "easy" way. If that
2480 * fails, we'll save the log entries for later.
2482 if (expireq_locked) {
2483 TCPLOG_EXPIREQ_UNLOCK();
2484 expireq_locked = false;
2487 /* Lock the INP and then re-check the state. */
2488 inp = cur_tln->tln_inp;
2491 * If we caught this while it was transitioning, the data
2492 * might have moved from the TCPCB to the tln (signified by
2493 * setting tln_closed to true. If so, treat this like an
2494 * inactive connection.
2496 if (cur_tln->tln_closed) {
2498 * It looks like we may have caught this connection
2499 * while it was transitioning from active to inactive.
2500 * Treat this like an inactive connection.
2507 * Try to dump the data from the tp without dropping the lock.
2508 * If this fails, try to save off the data locally.
2510 tp = cur_tln->tln_tp;
2511 if (tcp_log_dump_tp_logbuf(tp, reason, M_NOWAIT, true) &&
2512 num_local_entries < LOCAL_SAVE) {
2513 tcp_log_move_tp_to_node(tp,
2514 &local_entries[num_local_entries]);
2515 local_entries[num_local_entries].tln_closed = 1;
2516 KASSERT(local_entries[num_local_entries].tln_bucket ==
2517 tlb, ("%s: %d: bucket mismatch for node %p",
2518 __func__, __LINE__, cur_tln));
2519 num_local_entries++;
2525 * We are goint to leave the current tln on the list. It will
2526 * become the previous tln.
2531 /* Drop our locks, if any. */
2532 KASSERT(tree_locked == TREE_UNLOCKED,
2533 ("%s: %d: tree unexpectedly locked", __func__, __LINE__));
2534 switch (tree_locked) {
2536 TCPID_TREE_WUNLOCK();
2537 tree_locked = TREE_UNLOCKED;
2540 TCPID_TREE_RUNLOCK();
2541 tree_locked = TREE_UNLOCKED;
2544 if (expireq_locked) {
2545 TCPLOG_EXPIREQ_UNLOCK();
2546 expireq_locked = false;
2550 * Try again for any saved entries. tcp_log_dump_node_logbuf() is
2551 * guaranteed to free the log entries within the node. And, since
2552 * the node itself is on our stack, we don't need to free it.
2554 for (i = 0; i < num_local_entries; i++)
2555 tcp_log_dump_node_logbuf(&local_entries[i], reason, M_WAITOK);
2557 /* Drop our reference. */
2558 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
2559 TCPID_BUCKET_UNLOCK(tlb);
2562 /* Drop our locks, if any. */
2563 switch (tree_locked) {
2565 TCPID_TREE_WUNLOCK();
2568 TCPID_TREE_RUNLOCK();
2572 TCPLOG_EXPIREQ_UNLOCK();
2578 * Queue the log buffers for all sessions in a bucket for transmissions via
2579 * the log buffer facility.
2581 * NOTE: This should be called with a locked INP; however, the function
2582 * will drop the lock.
2585 tcp_log_dump_tp_bucket_logbufs(struct tcpcb *tp, char *reason)
2587 struct tcp_log_id_bucket *tlb;
2590 /* Figure out our bucket and lock it. */
2591 INP_WLOCK_ASSERT(tp->t_inpcb);
2595 * No bucket; treat this like a request to dump a single
2598 (void)tcp_log_dump_tp_logbuf(tp, reason, M_WAITOK, true);
2599 INP_WUNLOCK(tp->t_inpcb);
2602 TCPID_BUCKET_REF(tlb);
2603 INP_WUNLOCK(tp->t_inpcb);
2604 TCPID_BUCKET_LOCK(tlb);
2606 /* If we are the last reference, we have nothing more to do here. */
2607 tree_locked = TREE_UNLOCKED;
2608 if (tcp_log_unref_bucket(tlb, &tree_locked, NULL)) {
2609 switch (tree_locked) {
2611 TCPID_TREE_WUNLOCK();
2614 TCPID_TREE_RUNLOCK();
2620 /* Turn this over to tcp_log_dumpbucketlogs() to finish the work. */
2621 tcp_log_dumpbucketlogs(tlb, reason);
2625 * Mark the end of a flow with the current stack. A stack can add
2626 * stack-specific info to this trace event by overriding this
2627 * function (see bbr_log_flowend() for example).
2630 tcp_log_flowend(struct tcpcb *tp)
2632 if (tp->t_logstate != TCP_LOG_STATE_OFF) {
2633 struct socket *so = tp->t_inpcb->inp_socket;
2634 TCP_LOG_EVENT(tp, NULL, &so->so_rcv, &so->so_snd,
2635 TCP_LOG_FLOWEND, 0, 0, NULL, false);