1
2 /*-
3 * SPDX-License-Identifier: BSD-2-Clause
4 *
5 * Copyright (c) 2016-2018 Netflix, Inc.
6 *
7 * Redistribution and use in source and binary forms, with or without
8 * modification, are permitted provided that the following conditions
9 * are met:
10 * 1. Redistributions of source code must retain the above copyright
11 * notice, this list of conditions and the following disclaimer.
12 * 2. Redistributions in binary form must reproduce the above copyright
13 * notice, this list of conditions and the following disclaimer in the
14 * documentation and/or other materials provided with the distribution.
15 *
16 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
17 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19 * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
20 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
21 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
22 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
23 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
24 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
25 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26 * SUCH DAMAGE.
27 *
28 */
29
30 #include <sys/cdefs.h>
31 #include "opt_inet.h"
32 #include <sys/param.h>
33 #include <sys/arb.h>
34 #include <sys/hash.h>
35 #include <sys/kernel.h>
36 #include <sys/lock.h>
37 #include <sys/malloc.h>
38 #include <sys/mutex.h>
39 #include <sys/qmath.h>
40 #include <sys/queue.h>
41 #include <sys/refcount.h>
42 #include <sys/rwlock.h>
43 #include <sys/socket.h>
44 #include <sys/socketvar.h>
45 #include <sys/sysctl.h>
46 #include <sys/tree.h>
47 #include <sys/stats.h> /* Must come after qmath.h and tree.h */
48 #include <sys/counter.h>
49 #include <dev/tcp_log/tcp_log_dev.h>
50
51 #include <net/if.h>
52 #include <net/if_var.h>
53 #include <net/vnet.h>
54
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>
60 #include <netinet/tcp_seq.h>
61 #include <netinet/tcp_hpts.h>
62
63 /* Default expiry time */
64 #define TCP_LOG_EXPIRE_TIME ((sbintime_t)60 * SBT_1S)
65
66 /* Max interval at which to run the expiry timer */
67 #define TCP_LOG_EXPIRE_INTVL ((sbintime_t)5 * SBT_1S)
68
69 bool tcp_log_verbose;
70 static uma_zone_t tcp_log_id_bucket_zone, tcp_log_id_node_zone, tcp_log_zone;
71 static int tcp_log_session_limit = TCP_LOG_BUF_DEFAULT_SESSION_LIMIT;
72 static uint32_t tcp_log_version = TCP_LOG_BUF_VER;
73 RB_HEAD(tcp_log_id_tree, tcp_log_id_bucket);
74 static struct tcp_log_id_tree tcp_log_id_head;
75 static STAILQ_HEAD(, tcp_log_id_node) tcp_log_expireq_head =
76 STAILQ_HEAD_INITIALIZER(tcp_log_expireq_head);
77 static struct mtx tcp_log_expireq_mtx;
78 static struct callout tcp_log_expireq_callout;
79 static u_long tcp_log_auto_ratio = 0;
80 static volatile u_long tcp_log_auto_ratio_cur = 0;
81 static uint32_t tcp_log_auto_mode = TCP_LOG_STATE_TAIL;
82 static bool tcp_log_auto_all = false;
83 static uint32_t tcp_disable_all_bb_logs = 0;
84
85 RB_PROTOTYPE_STATIC(tcp_log_id_tree, tcp_log_id_bucket, tlb_rb, tcp_log_id_cmp)
86
87 SYSCTL_NODE(_net_inet_tcp, OID_AUTO, bb, CTLFLAG_RW | CTLFLAG_MPSAFE, 0,
88 "TCP Black Box controls");
89
90 SYSCTL_NODE(_net_inet_tcp_bb, OID_AUTO, tp, CTLFLAG_RW | CTLFLAG_MPSAFE, 0,
91 "TCP Black Box Trace Point controls");
92
93 SYSCTL_BOOL(_net_inet_tcp_bb, OID_AUTO, log_verbose, CTLFLAG_RW, &tcp_log_verbose,
94 0, "Force verbose logging for TCP traces");
95
96 SYSCTL_INT(_net_inet_tcp_bb, OID_AUTO, log_session_limit,
97 CTLFLAG_RW, &tcp_log_session_limit, 0,
98 "Maximum number of events maintained for each TCP session");
99
100 uint32_t tcp_trace_point_config = 0;
101 SYSCTL_U32(_net_inet_tcp_bb_tp, OID_AUTO, number, CTLFLAG_RW,
102 &tcp_trace_point_config, TCP_LOG_STATE_HEAD_AUTO,
103 "What is the trace point number to activate (0=none, 0xffffffff = all)?");
104
105 uint32_t tcp_trace_point_bb_mode = TCP_LOG_STATE_CONTINUAL;
106 SYSCTL_U32(_net_inet_tcp_bb_tp, OID_AUTO, bbmode, CTLFLAG_RW,
107 &tcp_trace_point_bb_mode, TCP_LOG_STATE_HEAD_AUTO,
108 "What is BB logging mode that is activated?");
109
110 int32_t tcp_trace_point_count = 0;
111 SYSCTL_U32(_net_inet_tcp_bb_tp, OID_AUTO, count, CTLFLAG_RW,
112 &tcp_trace_point_count, TCP_LOG_STATE_HEAD_AUTO,
113 "How many connections will have BB logging turned on that hit the tracepoint?");
114
115
116
117 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_global_limit, CTLFLAG_RW,
118 &tcp_log_zone, "Maximum number of events maintained for all TCP sessions");
119
120 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_global_entries, CTLFLAG_RD,
121 &tcp_log_zone, "Current number of events maintained for all TCP sessions");
122
123 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_id_limit, CTLFLAG_RW,
124 &tcp_log_id_bucket_zone, "Maximum number of log IDs");
125
126 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_id_entries, CTLFLAG_RD,
127 &tcp_log_id_bucket_zone, "Current number of log IDs");
128
129 SYSCTL_UMA_MAX(_net_inet_tcp_bb, OID_AUTO, log_id_tcpcb_limit, CTLFLAG_RW,
130 &tcp_log_id_node_zone, "Maximum number of tcpcbs with log IDs");
131
132 SYSCTL_UMA_CUR(_net_inet_tcp_bb, OID_AUTO, log_id_tcpcb_entries, CTLFLAG_RD,
133 &tcp_log_id_node_zone, "Current number of tcpcbs with log IDs");
134
135 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, log_version, CTLFLAG_RD, &tcp_log_version,
136 0, "Version of log formats exported");
137
138 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, disable_all, CTLFLAG_RW,
139 &tcp_disable_all_bb_logs, 0,
140 "Disable all BB logging for all connections");
141
142 SYSCTL_ULONG(_net_inet_tcp_bb, OID_AUTO, log_auto_ratio, CTLFLAG_RW,
143 &tcp_log_auto_ratio, 0, "Do auto capturing for 1 out of N sessions");
144
145 SYSCTL_U32(_net_inet_tcp_bb, OID_AUTO, log_auto_mode, CTLFLAG_RW,
146 &tcp_log_auto_mode, 0,
147 "Logging mode for auto-selected sessions (default is TCP_LOG_STATE_TAIL)");
148
149 SYSCTL_BOOL(_net_inet_tcp_bb, OID_AUTO, log_auto_all, CTLFLAG_RW,
150 &tcp_log_auto_all, 0,
151 "Auto-select from all sessions (rather than just those with IDs)");
152
153 #ifdef TCPLOG_DEBUG_COUNTERS
154 counter_u64_t tcp_log_queued;
155 counter_u64_t tcp_log_que_fail1;
156 counter_u64_t tcp_log_que_fail2;
157 counter_u64_t tcp_log_que_fail3;
158 counter_u64_t tcp_log_que_fail4;
159 counter_u64_t tcp_log_que_fail5;
160 counter_u64_t tcp_log_que_copyout;
161 counter_u64_t tcp_log_que_read;
162 counter_u64_t tcp_log_que_freed;
163
164 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, queued, CTLFLAG_RD,
165 &tcp_log_queued, "Number of entries queued");
166 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail1, CTLFLAG_RD,
167 &tcp_log_que_fail1, "Number of entries queued but fail 1");
168 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail2, CTLFLAG_RD,
169 &tcp_log_que_fail2, "Number of entries queued but fail 2");
170 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail3, CTLFLAG_RD,
171 &tcp_log_que_fail3, "Number of entries queued but fail 3");
172 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail4, CTLFLAG_RD,
173 &tcp_log_que_fail4, "Number of entries queued but fail 4");
174 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, fail5, CTLFLAG_RD,
175 &tcp_log_que_fail5, "Number of entries queued but fail 4");
176 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, copyout, CTLFLAG_RD,
177 &tcp_log_que_copyout, "Number of entries copied out");
178 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, read, CTLFLAG_RD,
179 &tcp_log_que_read, "Number of entries read from the queue");
180 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, freed, CTLFLAG_RD,
181 &tcp_log_que_freed, "Number of entries freed after reading");
182 #endif
183
184 #ifdef INVARIANTS
185 #define TCPLOG_DEBUG_RINGBUF
186 #endif
187 /* Number of requests to consider a PBCID "active". */
188 #define ACTIVE_REQUEST_COUNT 10
189
190 /* Statistic tracking for "active" PBCIDs. */
191 static counter_u64_t tcp_log_pcb_ids_cur;
192 static counter_u64_t tcp_log_pcb_ids_tot;
193
194 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_cur, CTLFLAG_RD,
195 &tcp_log_pcb_ids_cur, "Number of pcb IDs allocated in the system");
196 SYSCTL_COUNTER_U64(_net_inet_tcp_bb, OID_AUTO, pcb_ids_tot, CTLFLAG_RD,
197 &tcp_log_pcb_ids_tot, "Total number of pcb IDs that have been allocated");
198
199 struct tcp_log_mem
200 {
201 STAILQ_ENTRY(tcp_log_mem) tlm_queue;
202 struct tcp_log_buffer tlm_buf;
203 struct tcp_log_verbose tlm_v;
204 #ifdef TCPLOG_DEBUG_RINGBUF
205 volatile int tlm_refcnt;
206 #endif
207 };
208
209 /* 60 bytes for the header, + 16 bytes for padding */
210 static uint8_t zerobuf[76];
211
212 /*
213 * Lock order:
214 * 1. TCPID_TREE
215 * 2. TCPID_BUCKET
216 * 3. INP
217 *
218 * Rules:
219 * A. You need a lock on the Tree to add/remove buckets.
220 * B. You need a lock on the bucket to add/remove nodes from the bucket.
221 * C. To change information in a node, you need the INP lock if the tln_closed
222 * field is false. Otherwise, you need the bucket lock. (Note that the
223 * tln_closed field can change at any point, so you need to recheck the
224 * entry after acquiring the INP lock.)
225 * D. To remove a node from the bucket, you must have that entry locked,
226 * according to the criteria of Rule C. Also, the node must not be on
227 * the expiry queue.
228 * E. The exception to C is the expiry queue fields, which are locked by
229 * the TCPLOG_EXPIREQ lock.
230 *
231 * Buckets have a reference count. Each node is a reference. Further,
232 * other callers may add reference counts to keep a bucket from disappearing.
233 * You can add a reference as long as you own a lock sufficient to keep the
234 * bucket from disappearing. For example, a common use is:
235 * a. Have a locked INP, but need to lock the TCPID_BUCKET.
236 * b. Add a refcount on the bucket. (Safe because the INP lock prevents
237 * the TCPID_BUCKET from going away.)
238 * c. Drop the INP lock.
239 * d. Acquire a lock on the TCPID_BUCKET.
240 * e. Acquire a lock on the INP.
241 * f. Drop the refcount on the bucket.
242 * (At this point, the bucket may disappear.)
243 *
244 * Expire queue lock:
245 * You can acquire this with either the bucket or INP lock. Don't reverse it.
246 * When the expire code has committed to freeing a node, it resets the expiry
247 * time to SBT_MAX. That is the signal to everyone else that they should
248 * leave that node alone.
249 */
250 static struct rwlock tcp_id_tree_lock;
251 #define TCPID_TREE_WLOCK() rw_wlock(&tcp_id_tree_lock)
252 #define TCPID_TREE_RLOCK() rw_rlock(&tcp_id_tree_lock)
253 #define TCPID_TREE_UPGRADE() rw_try_upgrade(&tcp_id_tree_lock)
254 #define TCPID_TREE_WUNLOCK() rw_wunlock(&tcp_id_tree_lock)
255 #define TCPID_TREE_RUNLOCK() rw_runlock(&tcp_id_tree_lock)
256 #define TCPID_TREE_WLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_WLOCKED)
257 #define TCPID_TREE_RLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_RLOCKED)
258 #define TCPID_TREE_UNLOCK_ASSERT() rw_assert(&tcp_id_tree_lock, RA_UNLOCKED)
259
260 #define TCPID_BUCKET_LOCK_INIT(tlb) mtx_init(&((tlb)->tlb_mtx), "tcp log id bucket", NULL, MTX_DEF)
261 #define TCPID_BUCKET_LOCK_DESTROY(tlb) mtx_destroy(&((tlb)->tlb_mtx))
262 #define TCPID_BUCKET_LOCK(tlb) mtx_lock(&((tlb)->tlb_mtx))
263 #define TCPID_BUCKET_UNLOCK(tlb) mtx_unlock(&((tlb)->tlb_mtx))
264 #define TCPID_BUCKET_LOCK_ASSERT(tlb) mtx_assert(&((tlb)->tlb_mtx), MA_OWNED)
265 #define TCPID_BUCKET_UNLOCK_ASSERT(tlb) mtx_assert(&((tlb)->tlb_mtx), MA_NOTOWNED)
266
267 #define TCPID_BUCKET_REF(tlb) refcount_acquire(&((tlb)->tlb_refcnt))
268 #define TCPID_BUCKET_UNREF(tlb) refcount_release(&((tlb)->tlb_refcnt))
269
270 #define TCPLOG_EXPIREQ_LOCK() mtx_lock(&tcp_log_expireq_mtx)
271 #define TCPLOG_EXPIREQ_UNLOCK() mtx_unlock(&tcp_log_expireq_mtx)
272
273 SLIST_HEAD(tcp_log_id_head, tcp_log_id_node);
274
275 struct tcp_log_id_bucket
276 {
277 /*
278 * tlb_id must be first. This lets us use strcmp on
279 * (struct tcp_log_id_bucket *) and (char *) interchangeably.
280 */
281 char tlb_id[TCP_LOG_ID_LEN];
282 char tlb_tag[TCP_LOG_TAG_LEN];
283 RB_ENTRY(tcp_log_id_bucket) tlb_rb;
284 struct tcp_log_id_head tlb_head;
285 struct mtx tlb_mtx;
286 volatile u_int tlb_refcnt;
287 volatile u_int tlb_reqcnt;
288 uint32_t tlb_loglimit;
289 int8_t tlb_logstate;
290 };
291
292 struct tcp_log_id_node
293 {
294 SLIST_ENTRY(tcp_log_id_node) tln_list;
295 STAILQ_ENTRY(tcp_log_id_node) tln_expireq; /* Locked by the expireq lock */
296 sbintime_t tln_expiretime; /* Locked by the expireq lock */
297
298 /*
299 * If INP is NULL, that means the connection has closed. We've
300 * saved the connection endpoint information and the log entries
301 * in the tln_ie and tln_entries members. We've also saved a pointer
302 * to the enclosing bucket here. If INP is not NULL, the information is
303 * in the PCB and not here.
304 */
305 struct inpcb *tln_inp;
306 struct tcpcb *tln_tp;
307 struct tcp_log_id_bucket *tln_bucket;
308 struct in_endpoints tln_ie;
309 struct tcp_log_stailq tln_entries;
310 int tln_count;
311 volatile int tln_closed;
312 uint8_t tln_af;
313 };
314
315 enum tree_lock_state {
316 TREE_UNLOCKED = 0,
317 TREE_RLOCKED,
318 TREE_WLOCKED,
319 };
320
321 /* Do we want to select this session for auto-logging? */
322 static __inline bool
tcp_log_selectauto(void)323 tcp_log_selectauto(void)
324 {
325
326 /*
327 * If we are doing auto-capturing, figure out whether we will capture
328 * this session.
329 */
330 if (tcp_log_auto_ratio &&
331 (tcp_disable_all_bb_logs == 0) &&
332 (atomic_fetchadd_long(&tcp_log_auto_ratio_cur, 1) %
333 tcp_log_auto_ratio) == 0)
334 return (true);
335 return (false);
336 }
337
338 static __inline int
tcp_log_id_cmp(struct tcp_log_id_bucket * a,struct tcp_log_id_bucket * b)339 tcp_log_id_cmp(struct tcp_log_id_bucket *a, struct tcp_log_id_bucket *b)
340 {
341 KASSERT(a != NULL, ("tcp_log_id_cmp: argument a is unexpectedly NULL"));
342 KASSERT(b != NULL, ("tcp_log_id_cmp: argument b is unexpectedly NULL"));
343 return strncmp(a->tlb_id, b->tlb_id, TCP_LOG_ID_LEN);
344 }
345
RB_GENERATE_STATIC(tcp_log_id_tree,tcp_log_id_bucket,tlb_rb,tcp_log_id_cmp)346 RB_GENERATE_STATIC(tcp_log_id_tree, tcp_log_id_bucket, tlb_rb, tcp_log_id_cmp)
347
348 static __inline void
349 tcp_log_id_validate_tree_lock(int tree_locked)
350 {
351
352 #ifdef INVARIANTS
353 switch (tree_locked) {
354 case TREE_WLOCKED:
355 TCPID_TREE_WLOCK_ASSERT();
356 break;
357 case TREE_RLOCKED:
358 TCPID_TREE_RLOCK_ASSERT();
359 break;
360 case TREE_UNLOCKED:
361 TCPID_TREE_UNLOCK_ASSERT();
362 break;
363 default:
364 kassert_panic("%s:%d: unknown tree lock state", __func__,
365 __LINE__);
366 }
367 #endif
368 }
369
370 static __inline void
tcp_log_remove_bucket(struct tcp_log_id_bucket * tlb)371 tcp_log_remove_bucket(struct tcp_log_id_bucket *tlb)
372 {
373
374 TCPID_TREE_WLOCK_ASSERT();
375 KASSERT(SLIST_EMPTY(&tlb->tlb_head),
376 ("%s: Attempt to remove non-empty bucket", __func__));
377 if (RB_REMOVE(tcp_log_id_tree, &tcp_log_id_head, tlb) == NULL) {
378 #ifdef INVARIANTS
379 kassert_panic("%s:%d: error removing element from tree",
380 __func__, __LINE__);
381 #endif
382 }
383 TCPID_BUCKET_LOCK_DESTROY(tlb);
384 counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1);
385 uma_zfree(tcp_log_id_bucket_zone, tlb);
386 }
387
388 /*
389 * Call with a referenced and locked bucket.
390 * Will return true if the bucket was freed; otherwise, false.
391 * tlb: The bucket to unreference.
392 * tree_locked: A pointer to the state of the tree lock. If the tree lock
393 * state changes, the function will update it.
394 * inp: If not NULL and the function needs to drop the inp lock to relock the
395 * tree, it will do so. (The caller must ensure inp will not become invalid,
396 * probably by holding a reference to it.)
397 */
398 static bool
tcp_log_unref_bucket(struct tcp_log_id_bucket * tlb,int * tree_locked,struct inpcb * inp)399 tcp_log_unref_bucket(struct tcp_log_id_bucket *tlb, int *tree_locked,
400 struct inpcb *inp)
401 {
402
403 KASSERT(tlb != NULL, ("%s: called with NULL tlb", __func__));
404 KASSERT(tree_locked != NULL, ("%s: called with NULL tree_locked",
405 __func__));
406
407 tcp_log_id_validate_tree_lock(*tree_locked);
408
409 /*
410 * Did we hold the last reference on the tlb? If so, we may need
411 * to free it. (Note that we can realistically only execute the
412 * loop twice: once without a write lock and once with a write
413 * lock.)
414 */
415 while (TCPID_BUCKET_UNREF(tlb)) {
416 /*
417 * We need a write lock on the tree to free this.
418 * If we can upgrade the tree lock, this is "easy". If we
419 * can't upgrade the tree lock, we need to do this the
420 * "hard" way: unwind all our locks and relock everything.
421 * In the meantime, anything could have changed. We even
422 * need to validate that we still need to free the bucket.
423 */
424 if (*tree_locked == TREE_RLOCKED && TCPID_TREE_UPGRADE())
425 *tree_locked = TREE_WLOCKED;
426 else if (*tree_locked != TREE_WLOCKED) {
427 TCPID_BUCKET_REF(tlb);
428 if (inp != NULL)
429 INP_WUNLOCK(inp);
430 TCPID_BUCKET_UNLOCK(tlb);
431 if (*tree_locked == TREE_RLOCKED)
432 TCPID_TREE_RUNLOCK();
433 TCPID_TREE_WLOCK();
434 *tree_locked = TREE_WLOCKED;
435 TCPID_BUCKET_LOCK(tlb);
436 if (inp != NULL)
437 INP_WLOCK(inp);
438 continue;
439 }
440
441 /*
442 * We have an empty bucket and a write lock on the tree.
443 * Remove the empty bucket.
444 */
445 tcp_log_remove_bucket(tlb);
446 return (true);
447 }
448 return (false);
449 }
450
451 /*
452 * Call with a locked bucket. This function will release the lock on the
453 * bucket before returning.
454 *
455 * The caller is responsible for freeing the tp->t_lin/tln node!
456 *
457 * Note: one of tp or both tlb and tln must be supplied.
458 *
459 * inp: A pointer to the inp. If the function needs to drop the inp lock to
460 * acquire the tree write lock, it will do so. (The caller must ensure inp
461 * will not become invalid, probably by holding a reference to it.)
462 * tp: A pointer to the tcpcb. (optional; if specified, tlb and tln are ignored)
463 * tlb: A pointer to the bucket. (optional; ignored if tp is specified)
464 * tln: A pointer to the node. (optional; ignored if tp is specified)
465 * tree_locked: A pointer to the state of the tree lock. If the tree lock
466 * state changes, the function will update it.
467 *
468 * Will return true if the INP lock was reacquired; otherwise, false.
469 */
470 static bool
tcp_log_remove_id_node(struct inpcb * inp,struct tcpcb * tp,struct tcp_log_id_bucket * tlb,struct tcp_log_id_node * tln,int * tree_locked)471 tcp_log_remove_id_node(struct inpcb *inp, struct tcpcb *tp,
472 struct tcp_log_id_bucket *tlb, struct tcp_log_id_node *tln,
473 int *tree_locked)
474 {
475 int orig_tree_locked;
476
477 KASSERT(tp != NULL || (tlb != NULL && tln != NULL),
478 ("%s: called with tp=%p, tlb=%p, tln=%p", __func__,
479 tp, tlb, tln));
480 KASSERT(tree_locked != NULL, ("%s: called with NULL tree_locked",
481 __func__));
482
483 if (tp != NULL) {
484 tlb = tp->t_lib;
485 tln = tp->t_lin;
486 KASSERT(tlb != NULL, ("%s: unexpectedly NULL tlb", __func__));
487 KASSERT(tln != NULL, ("%s: unexpectedly NULL tln", __func__));
488 }
489
490 tcp_log_id_validate_tree_lock(*tree_locked);
491 TCPID_BUCKET_LOCK_ASSERT(tlb);
492
493 /*
494 * Remove the node, clear the log bucket and node from the TCPCB, and
495 * decrement the bucket refcount. In the process, if this is the
496 * last reference, the bucket will be freed.
497 */
498 SLIST_REMOVE(&tlb->tlb_head, tln, tcp_log_id_node, tln_list);
499 if (tp != NULL) {
500 tp->t_lib = NULL;
501 tp->t_lin = NULL;
502 }
503 orig_tree_locked = *tree_locked;
504 if (!tcp_log_unref_bucket(tlb, tree_locked, inp))
505 TCPID_BUCKET_UNLOCK(tlb);
506 return (*tree_locked != orig_tree_locked);
507 }
508
509 #define RECHECK_INP_CLEAN(cleanup) do { \
510 if (inp->inp_flags & INP_DROPPED) { \
511 rv = ECONNRESET; \
512 cleanup; \
513 goto done; \
514 } \
515 tp = intotcpcb(inp); \
516 } while (0)
517
518 #define RECHECK_INP() RECHECK_INP_CLEAN(/* noop */)
519
520 static void
tcp_log_grow_tlb(char * tlb_id,struct tcpcb * tp)521 tcp_log_grow_tlb(char *tlb_id, struct tcpcb *tp)
522 {
523
524 INP_WLOCK_ASSERT(tptoinpcb(tp));
525
526 #ifdef STATS
527 if (V_tcp_perconn_stats_enable == 2 && tp->t_stats == NULL)
528 (void)tcp_stats_sample_rollthedice(tp, tlb_id, strlen(tlb_id));
529 #endif
530 }
531
532 static void
tcp_log_increment_reqcnt(struct tcp_log_id_bucket * tlb)533 tcp_log_increment_reqcnt(struct tcp_log_id_bucket *tlb)
534 {
535
536 atomic_fetchadd_int(&tlb->tlb_reqcnt, 1);
537 }
538
539 int
tcp_log_apply_ratio(struct tcpcb * tp,int ratio)540 tcp_log_apply_ratio(struct tcpcb *tp, int ratio)
541 {
542 struct tcp_log_id_bucket *tlb;
543 struct inpcb *inp = tptoinpcb(tp);
544 uint32_t hash, ratio_hash_thresh;
545 int rv, tree_locked;
546
547 rv = 0;
548 tree_locked = TREE_UNLOCKED;
549 tlb = tp->t_lib;
550
551 INP_WLOCK_ASSERT(inp);
552 if (tlb == NULL) {
553 INP_WUNLOCK(inp);
554 return (EOPNOTSUPP);
555 }
556 if (ratio)
557 ratio_hash_thresh = max(1, UINT32_MAX / ratio);
558 else
559 ratio_hash_thresh = 0;
560 TCPID_BUCKET_REF(tlb);
561 INP_WUNLOCK(inp);
562 TCPID_BUCKET_LOCK(tlb);
563
564 hash = hash32_buf(tlb->tlb_id, strlen(tlb->tlb_id), 0);
565 if (hash > ratio_hash_thresh && tp->_t_logstate == TCP_LOG_STATE_OFF &&
566 tlb->tlb_logstate == TCP_LOG_STATE_OFF) {
567 /*
568 * Ratio decision not to log this log ID (and this connection by
569 * way of association). We only apply a log ratio log disable
570 * decision if it would not interfere with a log enable decision
571 * made elsewhere e.g. tcp_log_selectauto() or setsockopt().
572 */
573 tlb->tlb_logstate = TCP_LOG_STATE_RATIO_OFF;
574 INP_WLOCK(inp);
575 RECHECK_INP();
576 (void)tcp_log_state_change(tp, TCP_LOG_STATE_OFF);
577 done:
578 INP_WUNLOCK(inp);
579 }
580
581 INP_UNLOCK_ASSERT(inp);
582 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
583 TCPID_BUCKET_UNLOCK(tlb);
584
585 if (tree_locked == TREE_WLOCKED) {
586 TCPID_TREE_WLOCK_ASSERT();
587 TCPID_TREE_WUNLOCK();
588 } else if (tree_locked == TREE_RLOCKED) {
589 TCPID_TREE_RLOCK_ASSERT();
590 TCPID_TREE_RUNLOCK();
591 } else
592 TCPID_TREE_UNLOCK_ASSERT();
593
594 return (rv);
595 }
596
597 /*
598 * Associate the specified tag with a particular TCP log ID.
599 * Called with INPCB locked. Returns with it unlocked.
600 * Returns 0 on success or EOPNOTSUPP if the connection has no TCP log ID.
601 */
602 int
tcp_log_set_tag(struct tcpcb * tp,char * tag)603 tcp_log_set_tag(struct tcpcb *tp, char *tag)
604 {
605 struct inpcb *inp = tptoinpcb(tp);
606 struct tcp_log_id_bucket *tlb;
607 int tree_locked;
608
609 INP_WLOCK_ASSERT(inp);
610
611 tree_locked = TREE_UNLOCKED;
612 tlb = tp->t_lib;
613 if (tlb == NULL) {
614 INP_WUNLOCK(inp);
615 return (EOPNOTSUPP);
616 }
617
618 TCPID_BUCKET_REF(tlb);
619 INP_WUNLOCK(inp);
620 TCPID_BUCKET_LOCK(tlb);
621 strlcpy(tlb->tlb_tag, tag, TCP_LOG_TAG_LEN);
622 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
623 TCPID_BUCKET_UNLOCK(tlb);
624
625 if (tree_locked == TREE_WLOCKED) {
626 TCPID_TREE_WLOCK_ASSERT();
627 TCPID_TREE_WUNLOCK();
628 } else if (tree_locked == TREE_RLOCKED) {
629 TCPID_TREE_RLOCK_ASSERT();
630 TCPID_TREE_RUNLOCK();
631 } else
632 TCPID_TREE_UNLOCK_ASSERT();
633
634 return (0);
635 }
636
637 /*
638 * Set the TCP log ID for a TCPCB.
639 * Called with INPCB locked. Returns with it unlocked.
640 */
641 int
tcp_log_set_id(struct tcpcb * tp,char * id)642 tcp_log_set_id(struct tcpcb *tp, char *id)
643 {
644 struct tcp_log_id_bucket *tlb, *tmp_tlb;
645 struct tcp_log_id_node *tln;
646 struct inpcb *inp = tptoinpcb(tp);
647 int tree_locked, rv;
648 bool bucket_locked, same;
649
650 tlb = NULL;
651 tln = NULL;
652 tree_locked = TREE_UNLOCKED;
653 bucket_locked = false;
654
655 restart:
656 INP_WLOCK_ASSERT(inp);
657 /* See if the ID is unchanged. */
658 same = ((tp->t_lib != NULL && !strcmp(tp->t_lib->tlb_id, id)) ||
659 (tp->t_lib == NULL && *id == 0));
660 if (tp->_t_logstate && STAILQ_FIRST(&tp->t_logs) && !same) {
661 /*
662 * There are residual logs left we may
663 * be changing id's so dump what we can.
664 */
665 switch(tp->_t_logstate) {
666 case TCP_LOG_STATE_HEAD_AUTO:
667 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from head at id switch",
668 M_NOWAIT, false);
669 break;
670 case TCP_LOG_STATE_TAIL_AUTO:
671 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from tail at id switch",
672 M_NOWAIT, false);
673 break;
674 case TCP_LOG_STATE_CONTINUAL:
675 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual at id switch",
676 M_NOWAIT, false);
677 break;
678 case TCP_LOG_VIA_BBPOINTS:
679 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from bbpoints at id switch",
680 M_NOWAIT, false);
681 break;
682 }
683 }
684 if (same) {
685 if (tp->t_lib != NULL) {
686 tcp_log_increment_reqcnt(tp->t_lib);
687 if ((tp->t_lib->tlb_logstate > TCP_LOG_STATE_OFF) &&
688 (tp->t_log_state_set == 0)) {
689 /* Clone in any logging */
690
691 tp->_t_logstate = tp->t_lib->tlb_logstate;
692 }
693 if ((tp->t_lib->tlb_loglimit) &&
694 (tp->t_log_state_set == 0)) {
695 /* We also have a limit set */
696
697 tp->t_loglimit = tp->t_lib->tlb_loglimit;
698 }
699 }
700 rv = 0;
701 goto done;
702 }
703
704 /*
705 * If the TCPCB had a previous ID, we need to extricate it from
706 * the previous list.
707 *
708 * Drop the TCPCB lock and lock the tree and the bucket.
709 * Because this is called in the socket context, we (theoretically)
710 * don't need to worry about the INPCB completely going away
711 * while we are gone.
712 */
713 if (tp->t_lib != NULL) {
714 tlb = tp->t_lib;
715 TCPID_BUCKET_REF(tlb);
716 INP_WUNLOCK(inp);
717
718 if (tree_locked == TREE_UNLOCKED) {
719 TCPID_TREE_RLOCK();
720 tree_locked = TREE_RLOCKED;
721 }
722 TCPID_BUCKET_LOCK(tlb);
723 bucket_locked = true;
724 INP_WLOCK(inp);
725
726 /*
727 * Unreference the bucket. If our bucket went away, it is no
728 * longer locked or valid.
729 */
730 if (tcp_log_unref_bucket(tlb, &tree_locked, inp)) {
731 bucket_locked = false;
732 tlb = NULL;
733 }
734
735 /* Validate the INP. */
736 RECHECK_INP();
737
738 /*
739 * Evaluate whether the bucket changed while we were unlocked.
740 *
741 * Possible scenarios here:
742 * 1. Bucket is unchanged and the same one we started with.
743 * 2. The TCPCB no longer has a bucket and our bucket was
744 * freed.
745 * 3. The TCPCB has a new bucket, whether ours was freed.
746 * 4. The TCPCB no longer has a bucket and our bucket was
747 * not freed.
748 *
749 * In cases 2-4, we will start over. In case 1, we will
750 * proceed here to remove the bucket.
751 */
752 if (tlb == NULL || tp->t_lib != tlb) {
753 KASSERT(bucket_locked || tlb == NULL,
754 ("%s: bucket_locked (%d) and tlb (%p) are "
755 "inconsistent", __func__, bucket_locked, tlb));
756
757 if (bucket_locked) {
758 TCPID_BUCKET_UNLOCK(tlb);
759 bucket_locked = false;
760 tlb = NULL;
761 }
762 goto restart;
763 }
764
765 /*
766 * Store the (struct tcp_log_id_node) for reuse. Then, remove
767 * it from the bucket. In the process, we may end up relocking.
768 * If so, we need to validate that the INP is still valid, and
769 * the TCPCB entries match we expect.
770 *
771 * We will clear tlb and change the bucket_locked state just
772 * before calling tcp_log_remove_id_node(), since that function
773 * will unlock the bucket.
774 */
775 if (tln != NULL)
776 uma_zfree(tcp_log_id_node_zone, tln);
777 tln = tp->t_lin;
778 tlb = NULL;
779 bucket_locked = false;
780 if (tcp_log_remove_id_node(inp, tp, NULL, NULL, &tree_locked)) {
781 RECHECK_INP();
782
783 /*
784 * If the TCPCB moved to a new bucket while we had
785 * dropped the lock, restart.
786 */
787 if (tp->t_lib != NULL || tp->t_lin != NULL)
788 goto restart;
789 }
790
791 /*
792 * Yay! We successfully removed the TCPCB from its old
793 * bucket. Phew!
794 *
795 * On to bigger and better things...
796 */
797 }
798
799 /* At this point, the TCPCB should not be in any bucket. */
800 KASSERT(tp->t_lib == NULL, ("%s: tp->t_lib is not NULL", __func__));
801
802 /*
803 * If the new ID is not empty, we need to now assign this TCPCB to a
804 * new bucket.
805 */
806 if (*id) {
807 /* Get a new tln, if we don't already have one to reuse. */
808 if (tln == NULL) {
809 tln = uma_zalloc(tcp_log_id_node_zone,
810 M_NOWAIT | M_ZERO);
811 if (tln == NULL) {
812 rv = ENOBUFS;
813 goto done;
814 }
815 tln->tln_inp = inp;
816 tln->tln_tp = tp;
817 }
818
819 /*
820 * Drop the INP lock for a bit. We don't need it, and dropping
821 * it prevents lock order reversals.
822 */
823 INP_WUNLOCK(inp);
824
825 /* Make sure we have at least a read lock on the tree. */
826 tcp_log_id_validate_tree_lock(tree_locked);
827 if (tree_locked == TREE_UNLOCKED) {
828 TCPID_TREE_RLOCK();
829 tree_locked = TREE_RLOCKED;
830 }
831
832 refind:
833 /*
834 * Remember that we constructed (struct tcp_log_id_node) so
835 * we can safely cast the id to it for the purposes of finding.
836 */
837 KASSERT(tlb == NULL, ("%s:%d tlb unexpectedly non-NULL",
838 __func__, __LINE__));
839 tmp_tlb = RB_FIND(tcp_log_id_tree, &tcp_log_id_head,
840 (struct tcp_log_id_bucket *) id);
841
842 /*
843 * If we didn't find a matching bucket, we need to add a new
844 * one. This requires a write lock. But, of course, we will
845 * need to recheck some things when we re-acquire the lock.
846 */
847 if (tmp_tlb == NULL && tree_locked != TREE_WLOCKED) {
848 tree_locked = TREE_WLOCKED;
849 if (!TCPID_TREE_UPGRADE()) {
850 TCPID_TREE_RUNLOCK();
851 TCPID_TREE_WLOCK();
852
853 /*
854 * The tree may have changed while we were
855 * unlocked.
856 */
857 goto refind;
858 }
859 }
860
861 /* If we need to add a new bucket, do it now. */
862 if (tmp_tlb == NULL) {
863 /* Allocate new bucket. */
864 tlb = uma_zalloc(tcp_log_id_bucket_zone, M_NOWAIT);
865 if (tlb == NULL) {
866 rv = ENOBUFS;
867 goto done_noinp;
868 }
869 counter_u64_add(tcp_log_pcb_ids_cur, 1);
870 counter_u64_add(tcp_log_pcb_ids_tot, 1);
871
872 if ((tcp_log_auto_all == false) &&
873 tcp_log_auto_mode &&
874 tcp_log_selectauto()) {
875 /* Save off the log state */
876 tlb->tlb_logstate = tcp_log_auto_mode;
877 } else
878 tlb->tlb_logstate = TCP_LOG_STATE_OFF;
879 tlb->tlb_loglimit = 0;
880 tlb->tlb_tag[0] = '\0'; /* Default to an empty tag. */
881
882 /*
883 * Copy the ID to the bucket.
884 * NB: Don't use strlcpy() unless you are sure
885 * we've always validated NULL termination.
886 *
887 * TODO: When I'm done writing this, see if we
888 * we have correctly validated NULL termination and
889 * can use strlcpy(). :-)
890 */
891 strncpy(tlb->tlb_id, id, TCP_LOG_ID_LEN - 1);
892 tlb->tlb_id[TCP_LOG_ID_LEN - 1] = '\0';
893
894 /*
895 * Take the refcount for the first node and go ahead
896 * and lock this. Note that we zero the tlb_mtx
897 * structure, since 0xdeadc0de flips the right bits
898 * for the code to think that this mutex has already
899 * been initialized. :-(
900 */
901 SLIST_INIT(&tlb->tlb_head);
902 refcount_init(&tlb->tlb_refcnt, 1);
903 tlb->tlb_reqcnt = 1;
904 memset(&tlb->tlb_mtx, 0, sizeof(struct mtx));
905 TCPID_BUCKET_LOCK_INIT(tlb);
906 TCPID_BUCKET_LOCK(tlb);
907 bucket_locked = true;
908
909 #define FREE_NEW_TLB() do { \
910 TCPID_BUCKET_LOCK_DESTROY(tlb); \
911 uma_zfree(tcp_log_id_bucket_zone, tlb); \
912 counter_u64_add(tcp_log_pcb_ids_cur, (int64_t)-1); \
913 counter_u64_add(tcp_log_pcb_ids_tot, (int64_t)-1); \
914 bucket_locked = false; \
915 tlb = NULL; \
916 } while (0)
917 /*
918 * Relock the INP and make sure we are still
919 * unassigned.
920 */
921 INP_WLOCK(inp);
922 RECHECK_INP_CLEAN(FREE_NEW_TLB());
923 if (tp->t_lib != NULL) {
924 FREE_NEW_TLB();
925 goto restart;
926 }
927
928 /* Add the new bucket to the tree. */
929 tmp_tlb = RB_INSERT(tcp_log_id_tree, &tcp_log_id_head,
930 tlb);
931 KASSERT(tmp_tlb == NULL,
932 ("%s: Unexpected conflicting bucket (%p) while "
933 "adding new bucket (%p)", __func__, tmp_tlb, tlb));
934
935 /*
936 * If we found a conflicting bucket, free the new
937 * one we made and fall through to use the existing
938 * bucket.
939 */
940 if (tmp_tlb != NULL) {
941 FREE_NEW_TLB();
942 INP_WUNLOCK(inp);
943 }
944 #undef FREE_NEW_TLB
945 }
946
947 /* If we found an existing bucket, use it. */
948 if (tmp_tlb != NULL) {
949 tlb = tmp_tlb;
950 TCPID_BUCKET_LOCK(tlb);
951 bucket_locked = true;
952
953 /*
954 * Relock the INP and make sure we are still
955 * unassigned.
956 */
957 INP_UNLOCK_ASSERT(inp);
958 INP_WLOCK(inp);
959 RECHECK_INP();
960 if (tp->t_lib != NULL) {
961 TCPID_BUCKET_UNLOCK(tlb);
962 bucket_locked = false;
963 tlb = NULL;
964 goto restart;
965 }
966
967 /* Take a reference on the bucket. */
968 TCPID_BUCKET_REF(tlb);
969
970 /* Record the request. */
971 tcp_log_increment_reqcnt(tlb);
972 }
973
974 tcp_log_grow_tlb(tlb->tlb_id, tp);
975
976 /* Add the new node to the list. */
977 SLIST_INSERT_HEAD(&tlb->tlb_head, tln, tln_list);
978 tp->t_lib = tlb;
979 tp->t_lin = tln;
980 if (tp->t_lib->tlb_logstate > TCP_LOG_STATE_OFF) {
981 /* Clone in any logging */
982
983 tp->_t_logstate = tp->t_lib->tlb_logstate;
984 }
985 if (tp->t_lib->tlb_loglimit) {
986 /* The loglimit too */
987
988 tp->t_loglimit = tp->t_lib->tlb_loglimit;
989 }
990 tln = NULL;
991 }
992
993 rv = 0;
994
995 done:
996 /* Unlock things, as needed, and return. */
997 INP_WUNLOCK(inp);
998 done_noinp:
999 INP_UNLOCK_ASSERT(inp);
1000 if (bucket_locked) {
1001 TCPID_BUCKET_LOCK_ASSERT(tlb);
1002 TCPID_BUCKET_UNLOCK(tlb);
1003 } else if (tlb != NULL)
1004 TCPID_BUCKET_UNLOCK_ASSERT(tlb);
1005 if (tree_locked == TREE_WLOCKED) {
1006 TCPID_TREE_WLOCK_ASSERT();
1007 TCPID_TREE_WUNLOCK();
1008 } else if (tree_locked == TREE_RLOCKED) {
1009 TCPID_TREE_RLOCK_ASSERT();
1010 TCPID_TREE_RUNLOCK();
1011 } else
1012 TCPID_TREE_UNLOCK_ASSERT();
1013 if (tln != NULL)
1014 uma_zfree(tcp_log_id_node_zone, tln);
1015 return (rv);
1016 }
1017
1018 /*
1019 * Get the TCP log ID for a TCPCB.
1020 * Called with INPCB locked.
1021 * 'buf' must point to a buffer that is at least TCP_LOG_ID_LEN bytes long.
1022 * Returns number of bytes copied.
1023 */
1024 size_t
tcp_log_get_id(struct tcpcb * tp,char * buf)1025 tcp_log_get_id(struct tcpcb *tp, char *buf)
1026 {
1027 size_t len;
1028
1029 INP_LOCK_ASSERT(tptoinpcb(tp));
1030 if (tp->t_lib != NULL) {
1031 len = strlcpy(buf, tp->t_lib->tlb_id, TCP_LOG_ID_LEN);
1032 KASSERT(len < TCP_LOG_ID_LEN,
1033 ("%s:%d: tp->t_lib->tlb_id too long (%zu)",
1034 __func__, __LINE__, len));
1035 } else {
1036 *buf = '\0';
1037 len = 0;
1038 }
1039 return (len);
1040 }
1041
1042 /*
1043 * Get the tag associated with the TCPCB's log ID.
1044 * Called with INPCB locked. Returns with it unlocked.
1045 * 'buf' must point to a buffer that is at least TCP_LOG_TAG_LEN bytes long.
1046 * Returns number of bytes copied.
1047 */
1048 size_t
tcp_log_get_tag(struct tcpcb * tp,char * buf)1049 tcp_log_get_tag(struct tcpcb *tp, char *buf)
1050 {
1051 struct inpcb *inp = tptoinpcb(tp);
1052 struct tcp_log_id_bucket *tlb;
1053 size_t len;
1054 int tree_locked;
1055
1056 INP_WLOCK_ASSERT(inp);
1057
1058 tree_locked = TREE_UNLOCKED;
1059 tlb = tp->t_lib;
1060
1061 if (tlb != NULL) {
1062 TCPID_BUCKET_REF(tlb);
1063 INP_WUNLOCK(inp);
1064 TCPID_BUCKET_LOCK(tlb);
1065 len = strlcpy(buf, tlb->tlb_tag, TCP_LOG_TAG_LEN);
1066 KASSERT(len < TCP_LOG_TAG_LEN,
1067 ("%s:%d: tp->t_lib->tlb_tag too long (%zu)",
1068 __func__, __LINE__, len));
1069 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
1070 TCPID_BUCKET_UNLOCK(tlb);
1071
1072 if (tree_locked == TREE_WLOCKED) {
1073 TCPID_TREE_WLOCK_ASSERT();
1074 TCPID_TREE_WUNLOCK();
1075 } else if (tree_locked == TREE_RLOCKED) {
1076 TCPID_TREE_RLOCK_ASSERT();
1077 TCPID_TREE_RUNLOCK();
1078 } else
1079 TCPID_TREE_UNLOCK_ASSERT();
1080 } else {
1081 INP_WUNLOCK(inp);
1082 *buf = '\0';
1083 len = 0;
1084 }
1085
1086 return (len);
1087 }
1088
1089 /*
1090 * Get number of connections with the same log ID.
1091 * Log ID is taken from given TCPCB.
1092 * Called with INPCB locked.
1093 */
1094 u_int
tcp_log_get_id_cnt(struct tcpcb * tp)1095 tcp_log_get_id_cnt(struct tcpcb *tp)
1096 {
1097
1098 INP_WLOCK_ASSERT(tptoinpcb(tp));
1099 return ((tp->t_lib == NULL) ? 0 : tp->t_lib->tlb_refcnt);
1100 }
1101
1102 #ifdef TCPLOG_DEBUG_RINGBUF
1103 /*
1104 * Functions/macros to increment/decrement reference count for a log
1105 * entry. This should catch when we do a double-free/double-remove or
1106 * a double-add.
1107 */
1108 static inline void
_tcp_log_entry_refcnt_add(struct tcp_log_mem * log_entry,const char * func,int line)1109 _tcp_log_entry_refcnt_add(struct tcp_log_mem *log_entry, const char *func,
1110 int line)
1111 {
1112 int refcnt;
1113
1114 refcnt = atomic_fetchadd_int(&log_entry->tlm_refcnt, 1);
1115 if (refcnt != 0)
1116 panic("%s:%d: log_entry(%p)->tlm_refcnt is %d (expected 0)",
1117 func, line, log_entry, refcnt);
1118 }
1119 #define tcp_log_entry_refcnt_add(l) \
1120 _tcp_log_entry_refcnt_add((l), __func__, __LINE__)
1121
1122 static inline void
_tcp_log_entry_refcnt_rem(struct tcp_log_mem * log_entry,const char * func,int line)1123 _tcp_log_entry_refcnt_rem(struct tcp_log_mem *log_entry, const char *func,
1124 int line)
1125 {
1126 int refcnt;
1127
1128 refcnt = atomic_fetchadd_int(&log_entry->tlm_refcnt, -1);
1129 if (refcnt != 1)
1130 panic("%s:%d: log_entry(%p)->tlm_refcnt is %d (expected 1)",
1131 func, line, log_entry, refcnt);
1132 }
1133 #define tcp_log_entry_refcnt_rem(l) \
1134 _tcp_log_entry_refcnt_rem((l), __func__, __LINE__)
1135
1136 #else /* !TCPLOG_DEBUG_RINGBUF */
1137
1138 #define tcp_log_entry_refcnt_add(l)
1139 #define tcp_log_entry_refcnt_rem(l)
1140
1141 #endif
1142
1143 /*
1144 * Cleanup after removing a log entry, but only decrement the count if we
1145 * are running INVARIANTS.
1146 */
1147 static inline void
tcp_log_free_log_common(struct tcp_log_mem * log_entry,int * count __unused)1148 tcp_log_free_log_common(struct tcp_log_mem *log_entry, int *count __unused)
1149 {
1150
1151 uma_zfree(tcp_log_zone, log_entry);
1152 #ifdef INVARIANTS
1153 (*count)--;
1154 KASSERT(*count >= 0,
1155 ("%s: count unexpectedly negative", __func__));
1156 #endif
1157 }
1158
1159 static void
tcp_log_free_entries(struct tcp_log_stailq * head,int * count)1160 tcp_log_free_entries(struct tcp_log_stailq *head, int *count)
1161 {
1162 struct tcp_log_mem *log_entry;
1163
1164 /* Free the entries. */
1165 while ((log_entry = STAILQ_FIRST(head)) != NULL) {
1166 STAILQ_REMOVE_HEAD(head, tlm_queue);
1167 tcp_log_entry_refcnt_rem(log_entry);
1168 tcp_log_free_log_common(log_entry, count);
1169 }
1170 }
1171
1172 /* Cleanup after removing a log entry. */
1173 static inline void
tcp_log_remove_log_cleanup(struct tcpcb * tp,struct tcp_log_mem * log_entry)1174 tcp_log_remove_log_cleanup(struct tcpcb *tp, struct tcp_log_mem *log_entry)
1175 {
1176 uma_zfree(tcp_log_zone, log_entry);
1177 tp->t_lognum--;
1178 KASSERT(tp->t_lognum >= 0,
1179 ("%s: tp->t_lognum unexpectedly negative", __func__));
1180 }
1181
1182 /* Remove a log entry from the head of a list. */
1183 static inline void
tcp_log_remove_log_head(struct tcpcb * tp,struct tcp_log_mem * log_entry)1184 tcp_log_remove_log_head(struct tcpcb *tp, struct tcp_log_mem *log_entry)
1185 {
1186
1187 KASSERT(log_entry == STAILQ_FIRST(&tp->t_logs),
1188 ("%s: attempt to remove non-HEAD log entry", __func__));
1189 STAILQ_REMOVE_HEAD(&tp->t_logs, tlm_queue);
1190 tcp_log_entry_refcnt_rem(log_entry);
1191 tcp_log_remove_log_cleanup(tp, log_entry);
1192 }
1193
1194 #ifdef TCPLOG_DEBUG_RINGBUF
1195 /*
1196 * Initialize the log entry's reference count, which we want to
1197 * survive allocations.
1198 */
1199 static int
tcp_log_zone_init(void * mem,int size,int flags __unused)1200 tcp_log_zone_init(void *mem, int size, int flags __unused)
1201 {
1202 struct tcp_log_mem *tlm;
1203
1204 KASSERT(size >= sizeof(struct tcp_log_mem),
1205 ("%s: unexpectedly short (%d) allocation", __func__, size));
1206 tlm = (struct tcp_log_mem *)mem;
1207 tlm->tlm_refcnt = 0;
1208 return (0);
1209 }
1210
1211 /*
1212 * Double check that the refcnt is zero on allocation and return.
1213 */
1214 static int
tcp_log_zone_ctor(void * mem,int size,void * args __unused,int flags __unused)1215 tcp_log_zone_ctor(void *mem, int size, void *args __unused, int flags __unused)
1216 {
1217 struct tcp_log_mem *tlm;
1218
1219 KASSERT(size >= sizeof(struct tcp_log_mem),
1220 ("%s: unexpectedly short (%d) allocation", __func__, size));
1221 tlm = (struct tcp_log_mem *)mem;
1222 if (tlm->tlm_refcnt != 0)
1223 panic("%s:%d: tlm(%p)->tlm_refcnt is %d (expected 0)",
1224 __func__, __LINE__, tlm, tlm->tlm_refcnt);
1225 return (0);
1226 }
1227
1228 static void
tcp_log_zone_dtor(void * mem,int size,void * args __unused)1229 tcp_log_zone_dtor(void *mem, int size, void *args __unused)
1230 {
1231 struct tcp_log_mem *tlm;
1232
1233 KASSERT(size >= sizeof(struct tcp_log_mem),
1234 ("%s: unexpectedly short (%d) allocation", __func__, size));
1235 tlm = (struct tcp_log_mem *)mem;
1236 if (tlm->tlm_refcnt != 0)
1237 panic("%s:%d: tlm(%p)->tlm_refcnt is %d (expected 0)",
1238 __func__, __LINE__, tlm, tlm->tlm_refcnt);
1239 }
1240 #endif /* TCPLOG_DEBUG_RINGBUF */
1241
1242 /* Do global initialization. */
1243 void
tcp_log_init(void)1244 tcp_log_init(void)
1245 {
1246
1247 tcp_log_zone = uma_zcreate("tcp_log", sizeof(struct tcp_log_mem),
1248 #ifdef TCPLOG_DEBUG_RINGBUF
1249 tcp_log_zone_ctor, tcp_log_zone_dtor, tcp_log_zone_init,
1250 #else
1251 NULL, NULL, NULL,
1252 #endif
1253 NULL, UMA_ALIGN_PTR, 0);
1254 (void)uma_zone_set_max(tcp_log_zone, TCP_LOG_BUF_DEFAULT_GLOBAL_LIMIT);
1255 tcp_log_id_bucket_zone = uma_zcreate("tcp_log_id_bucket",
1256 sizeof(struct tcp_log_id_bucket), NULL, NULL, NULL, NULL,
1257 UMA_ALIGN_PTR, 0);
1258 tcp_log_id_node_zone = uma_zcreate("tcp_log_id_node",
1259 sizeof(struct tcp_log_id_node), NULL, NULL, NULL, NULL,
1260 UMA_ALIGN_PTR, 0);
1261 #ifdef TCPLOG_DEBUG_COUNTERS
1262 tcp_log_queued = counter_u64_alloc(M_WAITOK);
1263 tcp_log_que_fail1 = counter_u64_alloc(M_WAITOK);
1264 tcp_log_que_fail2 = counter_u64_alloc(M_WAITOK);
1265 tcp_log_que_fail3 = counter_u64_alloc(M_WAITOK);
1266 tcp_log_que_fail4 = counter_u64_alloc(M_WAITOK);
1267 tcp_log_que_fail5 = counter_u64_alloc(M_WAITOK);
1268 tcp_log_que_copyout = counter_u64_alloc(M_WAITOK);
1269 tcp_log_que_read = counter_u64_alloc(M_WAITOK);
1270 tcp_log_que_freed = counter_u64_alloc(M_WAITOK);
1271 #endif
1272 tcp_log_pcb_ids_cur = counter_u64_alloc(M_WAITOK);
1273 tcp_log_pcb_ids_tot = counter_u64_alloc(M_WAITOK);
1274
1275 rw_init_flags(&tcp_id_tree_lock, "TCP ID tree", RW_NEW);
1276 mtx_init(&tcp_log_expireq_mtx, "TCP log expireq", NULL, MTX_DEF);
1277 callout_init(&tcp_log_expireq_callout, 1);
1278 }
1279
1280 /* Do per-TCPCB initialization. */
1281 void
tcp_log_tcpcbinit(struct tcpcb * tp)1282 tcp_log_tcpcbinit(struct tcpcb *tp)
1283 {
1284
1285 /* A new TCPCB should start out zero-initialized. */
1286 STAILQ_INIT(&tp->t_logs);
1287
1288 /*
1289 * If we are doing auto-capturing, figure out whether we will capture
1290 * this session.
1291 */
1292 tp->t_loglimit = tcp_log_session_limit;
1293 if ((tcp_log_auto_all == true) &&
1294 tcp_log_auto_mode &&
1295 tcp_log_selectauto()) {
1296 tp->_t_logstate = tcp_log_auto_mode;
1297 tp->t_flags2 |= TF2_LOG_AUTO;
1298 }
1299 }
1300
1301 /* Remove entries */
1302 static void
tcp_log_expire(void * unused __unused)1303 tcp_log_expire(void *unused __unused)
1304 {
1305 struct tcp_log_id_bucket *tlb;
1306 struct tcp_log_id_node *tln;
1307 sbintime_t expiry_limit;
1308 int tree_locked;
1309
1310 TCPLOG_EXPIREQ_LOCK();
1311 if (callout_pending(&tcp_log_expireq_callout)) {
1312 /* Callout was reset. */
1313 TCPLOG_EXPIREQ_UNLOCK();
1314 return;
1315 }
1316
1317 /*
1318 * Process entries until we reach one that expires too far in the
1319 * future. Look one second in the future.
1320 */
1321 expiry_limit = getsbinuptime() + SBT_1S;
1322 tree_locked = TREE_UNLOCKED;
1323
1324 while ((tln = STAILQ_FIRST(&tcp_log_expireq_head)) != NULL &&
1325 tln->tln_expiretime <= expiry_limit) {
1326 if (!callout_active(&tcp_log_expireq_callout)) {
1327 /*
1328 * Callout was stopped. I guess we should
1329 * just quit at this point.
1330 */
1331 TCPLOG_EXPIREQ_UNLOCK();
1332 return;
1333 }
1334
1335 /*
1336 * Remove the node from the head of the list and unlock
1337 * the list. Change the expiry time to SBT_MAX as a signal
1338 * to other threads that we now own this.
1339 */
1340 STAILQ_REMOVE_HEAD(&tcp_log_expireq_head, tln_expireq);
1341 tln->tln_expiretime = SBT_MAX;
1342 TCPLOG_EXPIREQ_UNLOCK();
1343
1344 /*
1345 * Remove the node from the bucket.
1346 */
1347 tlb = tln->tln_bucket;
1348 TCPID_BUCKET_LOCK(tlb);
1349 if (tcp_log_remove_id_node(NULL, NULL, tlb, tln, &tree_locked)) {
1350 tcp_log_id_validate_tree_lock(tree_locked);
1351 if (tree_locked == TREE_WLOCKED)
1352 TCPID_TREE_WUNLOCK();
1353 else
1354 TCPID_TREE_RUNLOCK();
1355 tree_locked = TREE_UNLOCKED;
1356 }
1357
1358 /* Drop the INP reference. */
1359 INP_WLOCK(tln->tln_inp);
1360 if (!in_pcbrele_wlocked(tln->tln_inp))
1361 INP_WUNLOCK(tln->tln_inp);
1362
1363 /* Free the log records. */
1364 tcp_log_free_entries(&tln->tln_entries, &tln->tln_count);
1365
1366 /* Free the node. */
1367 uma_zfree(tcp_log_id_node_zone, tln);
1368
1369 /* Relock the expiry queue. */
1370 TCPLOG_EXPIREQ_LOCK();
1371 }
1372
1373 /*
1374 * We've expired all the entries we can. Do we need to reschedule
1375 * ourselves?
1376 */
1377 callout_deactivate(&tcp_log_expireq_callout);
1378 if (tln != NULL) {
1379 /*
1380 * Get max(now + TCP_LOG_EXPIRE_INTVL, tln->tln_expiretime) and
1381 * set the next callout to that. (This helps ensure we generally
1382 * run the callout no more often than desired.)
1383 */
1384 expiry_limit = getsbinuptime() + TCP_LOG_EXPIRE_INTVL;
1385 if (expiry_limit < tln->tln_expiretime)
1386 expiry_limit = tln->tln_expiretime;
1387 callout_reset_sbt(&tcp_log_expireq_callout, expiry_limit,
1388 SBT_1S, tcp_log_expire, NULL, C_ABSOLUTE);
1389 }
1390
1391 /* We're done. */
1392 TCPLOG_EXPIREQ_UNLOCK();
1393 return;
1394 }
1395
1396 /*
1397 * Move log data from the TCPCB to a new node. This will reset the TCPCB log
1398 * entries and log count; however, it will not touch other things from the
1399 * TCPCB (e.g. t_lin, t_lib).
1400 *
1401 * NOTE: Must hold a lock on the INP.
1402 */
1403 static void
tcp_log_move_tp_to_node(struct tcpcb * tp,struct tcp_log_id_node * tln)1404 tcp_log_move_tp_to_node(struct tcpcb *tp, struct tcp_log_id_node *tln)
1405 {
1406 struct inpcb *inp = tptoinpcb(tp);
1407
1408 INP_WLOCK_ASSERT(inp);
1409
1410 tln->tln_ie = inp->inp_inc.inc_ie;
1411 if (inp->inp_inc.inc_flags & INC_ISIPV6)
1412 tln->tln_af = AF_INET6;
1413 else
1414 tln->tln_af = AF_INET;
1415 tln->tln_entries = tp->t_logs;
1416 tln->tln_count = tp->t_lognum;
1417 tln->tln_bucket = tp->t_lib;
1418
1419 /* Clear information from the PCB. */
1420 STAILQ_INIT(&tp->t_logs);
1421 tp->t_lognum = 0;
1422 }
1423
1424 /* Do per-TCPCB cleanup */
1425 void
tcp_log_tcpcbfini(struct tcpcb * tp)1426 tcp_log_tcpcbfini(struct tcpcb *tp)
1427 {
1428 struct tcp_log_id_node *tln, *tln_first;
1429 struct tcp_log_mem *log_entry;
1430 sbintime_t callouttime;
1431
1432
1433 INP_WLOCK_ASSERT(tptoinpcb(tp));
1434 if (tp->_t_logstate) {
1435 union tcp_log_stackspecific log;
1436 struct timeval tv;
1437 #ifdef TCP_ACCOUNTING
1438 struct tcp_log_buffer *lgb;
1439 int i;
1440
1441 memset(&log, 0, sizeof(log));
1442 if (tp->t_flags2 & TF2_TCP_ACCOUNTING) {
1443 for (i = 0; i < TCP_NUM_CNT_COUNTERS; i++) {
1444 log.u_raw.u64_flex[i] = tp->tcp_cnt_counters[i];
1445 }
1446 lgb = tcp_log_event(tp, NULL,
1447 NULL,
1448 NULL,
1449 TCP_LOG_ACCOUNTING, 0,
1450 0, &log, false, NULL, NULL, 0, &tv);
1451 if (lgb != NULL) {
1452 lgb->tlb_flex1 = TCP_NUM_CNT_COUNTERS;
1453 lgb->tlb_flex2 = 1;
1454 } else
1455 goto skip_out;
1456 for (i = 0; i<TCP_NUM_CNT_COUNTERS; i++) {
1457 log.u_raw.u64_flex[i] = tp->tcp_proc_time[i];
1458 }
1459 lgb = tcp_log_event(tp, NULL,
1460 NULL,
1461 NULL,
1462 TCP_LOG_ACCOUNTING, 0,
1463 0, &log, false, NULL, NULL, 0, &tv);
1464 if (lgb != NULL) {
1465 lgb->tlb_flex1 = TCP_NUM_CNT_COUNTERS;
1466 lgb->tlb_flex2 = 2;
1467 }
1468 }
1469 skip_out:
1470 #endif
1471 log.u_bbr.timeStamp = tcp_get_usecs(&tv);
1472 log.u_bbr.cur_del_rate = tp->t_end_info;
1473 (void)tcp_log_event(tp, NULL,
1474 NULL,
1475 NULL,
1476 TCP_LOG_CONNEND, 0,
1477 0, &log, false, NULL, NULL, 0, &tv);
1478 }
1479 /*
1480 * If we were gathering packets to be automatically dumped, try to do
1481 * it now. If this succeeds, the log information in the TCPCB will be
1482 * cleared. Otherwise, we'll handle the log information as we do
1483 * for other states.
1484 */
1485 switch(tp->_t_logstate) {
1486 case TCP_LOG_STATE_HEAD_AUTO:
1487 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from head",
1488 M_NOWAIT, false);
1489 break;
1490 case TCP_LOG_STATE_TAIL_AUTO:
1491 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from tail",
1492 M_NOWAIT, false);
1493 break;
1494 case TCP_LOG_VIA_BBPOINTS:
1495 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from bbpoints",
1496 M_NOWAIT, false);
1497 break;
1498 case TCP_LOG_STATE_CONTINUAL:
1499 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
1500 M_NOWAIT, false);
1501 break;
1502 }
1503
1504 /*
1505 * There are two ways we could keep logs: per-socket or per-ID. If
1506 * we are tracking logs with an ID, then the logs survive the
1507 * destruction of the TCPCB.
1508 *
1509 * If the TCPCB is associated with an ID node, move the logs from the
1510 * TCPCB to the ID node. In theory, this is safe, for reasons which I
1511 * will now explain for my own benefit when I next need to figure out
1512 * this code. :-)
1513 *
1514 * We own the INP lock. Therefore, no one else can change the contents
1515 * of this node (Rule C). Further, no one can remove this node from
1516 * the bucket while we hold the lock (Rule D). Basically, no one can
1517 * mess with this node. That leaves two states in which we could be:
1518 *
1519 * 1. Another thread is currently waiting to acquire the INP lock, with
1520 * plans to do something with this node. When we drop the INP lock,
1521 * they will have a chance to do that. They will recheck the
1522 * tln_closed field (see note to Rule C) and then acquire the
1523 * bucket lock before proceeding further.
1524 *
1525 * 2. Another thread will try to acquire a lock at some point in the
1526 * future. If they try to acquire a lock before we set the
1527 * tln_closed field, they will follow state #1. If they try to
1528 * acquire a lock after we set the tln_closed field, they will be
1529 * able to make changes to the node, at will, following Rule C.
1530 *
1531 * Therefore, we currently own this node and can make any changes
1532 * we want. But, as soon as we set the tln_closed field to true, we
1533 * have effectively dropped our lock on the node. (For this reason, we
1534 * also need to make sure our writes are ordered correctly. An atomic
1535 * operation with "release" semantics should be sufficient.)
1536 */
1537
1538 if (tp->t_lin != NULL) {
1539 struct inpcb *inp = tptoinpcb(tp);
1540
1541 /* Copy the relevant information to the log entry. */
1542 tln = tp->t_lin;
1543 KASSERT(tln->tln_inp == inp,
1544 ("%s: Mismatched inp (tln->tln_inp=%p, tp inpcb=%p)",
1545 __func__, tln->tln_inp, inp));
1546 tcp_log_move_tp_to_node(tp, tln);
1547
1548 /* Clear information from the PCB. */
1549 tp->t_lin = NULL;
1550 tp->t_lib = NULL;
1551
1552 /*
1553 * Take a reference on the INP. This ensures that the INP
1554 * remains valid while the node is on the expiry queue. This
1555 * ensures the INP is valid for other threads that may be
1556 * racing to lock this node when we move it to the expire
1557 * queue.
1558 */
1559 in_pcbref(inp);
1560
1561 /*
1562 * Store the entry on the expiry list. The exact behavior
1563 * depends on whether we have entries to keep. If so, we
1564 * put the entry at the tail of the list and expire in
1565 * TCP_LOG_EXPIRE_TIME. Otherwise, we expire "now" and put
1566 * the entry at the head of the list. (Handling the cleanup
1567 * via the expiry timer lets us avoid locking messy-ness here.)
1568 */
1569 tln->tln_expiretime = getsbinuptime();
1570 TCPLOG_EXPIREQ_LOCK();
1571 if (tln->tln_count) {
1572 tln->tln_expiretime += TCP_LOG_EXPIRE_TIME;
1573 if (STAILQ_EMPTY(&tcp_log_expireq_head) &&
1574 !callout_active(&tcp_log_expireq_callout)) {
1575 /*
1576 * We are adding the first entry and a callout
1577 * is not currently scheduled; therefore, we
1578 * need to schedule one.
1579 */
1580 callout_reset_sbt(&tcp_log_expireq_callout,
1581 tln->tln_expiretime, SBT_1S, tcp_log_expire,
1582 NULL, C_ABSOLUTE);
1583 }
1584 STAILQ_INSERT_TAIL(&tcp_log_expireq_head, tln,
1585 tln_expireq);
1586 } else {
1587 callouttime = tln->tln_expiretime +
1588 TCP_LOG_EXPIRE_INTVL;
1589 tln_first = STAILQ_FIRST(&tcp_log_expireq_head);
1590
1591 if ((tln_first == NULL ||
1592 callouttime < tln_first->tln_expiretime) &&
1593 (callout_pending(&tcp_log_expireq_callout) ||
1594 !callout_active(&tcp_log_expireq_callout))) {
1595 /*
1596 * The list is empty, or we want to run the
1597 * expire code before the first entry's timer
1598 * fires. Also, we are in a case where a callout
1599 * is not actively running. We want to reset
1600 * the callout to occur sooner.
1601 */
1602 callout_reset_sbt(&tcp_log_expireq_callout,
1603 callouttime, SBT_1S, tcp_log_expire, NULL,
1604 C_ABSOLUTE);
1605 }
1606
1607 /*
1608 * Insert to the head, or just after the head, as
1609 * appropriate. (This might result in small
1610 * mis-orderings as a bunch of "expire now" entries
1611 * gather at the start of the list, but that should
1612 * not produce big problems, since the expire timer
1613 * will walk through all of them.)
1614 */
1615 if (tln_first == NULL ||
1616 tln->tln_expiretime < tln_first->tln_expiretime)
1617 STAILQ_INSERT_HEAD(&tcp_log_expireq_head, tln,
1618 tln_expireq);
1619 else
1620 STAILQ_INSERT_AFTER(&tcp_log_expireq_head,
1621 tln_first, tln, tln_expireq);
1622 }
1623 TCPLOG_EXPIREQ_UNLOCK();
1624
1625 /*
1626 * We are done messing with the tln. After this point, we
1627 * can't touch it. (Note that the "release" semantics should
1628 * be included with the TCPLOG_EXPIREQ_UNLOCK() call above.
1629 * Therefore, they should be unnecessary here. However, it
1630 * seems like a good idea to include them anyway, since we
1631 * really are releasing a lock here.)
1632 */
1633 atomic_store_rel_int(&tln->tln_closed, 1);
1634 } else {
1635 /* Remove log entries. */
1636 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1637 tcp_log_remove_log_head(tp, log_entry);
1638 KASSERT(tp->t_lognum == 0,
1639 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
1640 __func__, tp->t_lognum));
1641 }
1642
1643 /*
1644 * Change the log state to off (just in case anything tries to sneak
1645 * in a last-minute log).
1646 */
1647 tp->_t_logstate = TCP_LOG_STATE_OFF;
1648 }
1649
1650 static void
tcp_log_purge_tp_logbuf(struct tcpcb * tp)1651 tcp_log_purge_tp_logbuf(struct tcpcb *tp)
1652 {
1653 struct tcp_log_mem *log_entry;
1654
1655 INP_WLOCK_ASSERT(tptoinpcb(tp));
1656 if (tp->t_lognum == 0)
1657 return;
1658
1659 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1660 tcp_log_remove_log_head(tp, log_entry);
1661 KASSERT(tp->t_lognum == 0,
1662 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
1663 __func__, tp->t_lognum));
1664 tp->_t_logstate = TCP_LOG_STATE_OFF;
1665 }
1666
1667 /*
1668 * This logs an event for a TCP socket. Normally, this is called via
1669 * TCP_LOG_EVENT or TCP_LOG_EVENT_VERBOSE. See the documentation for
1670 * TCP_LOG_EVENT().
1671 */
1672
1673 struct tcp_log_buffer *
tcp_log_event(struct tcpcb * tp,struct tcphdr * th,struct sockbuf * rxbuf,struct sockbuf * txbuf,uint8_t eventid,int errornum,uint32_t len,union tcp_log_stackspecific * stackinfo,int th_hostorder,const char * output_caller,const char * func,int line,const struct timeval * itv)1674 tcp_log_event(struct tcpcb *tp, struct tcphdr *th, struct sockbuf *rxbuf,
1675 struct sockbuf *txbuf, uint8_t eventid, int errornum, uint32_t len,
1676 union tcp_log_stackspecific *stackinfo, int th_hostorder,
1677 const char *output_caller, const char *func, int line, const struct timeval *itv)
1678 {
1679 struct tcp_log_mem *log_entry;
1680 struct tcp_log_buffer *log_buf;
1681 int attempt_count = 0;
1682 struct tcp_log_verbose *log_verbose;
1683 uint32_t logsn;
1684
1685 KASSERT((func == NULL && line == 0) || (func != NULL && line > 0),
1686 ("%s called with inconsistent func (%p) and line (%d) arguments",
1687 __func__, func, line));
1688
1689 INP_WLOCK_ASSERT(tptoinpcb(tp));
1690 if (tcp_disable_all_bb_logs) {
1691 /*
1692 * The global shutdown logging
1693 * switch has been thrown. Call
1694 * the purge function that frees
1695 * purges out the logs and
1696 * turns off logging.
1697 */
1698 tcp_log_purge_tp_logbuf(tp);
1699 return (NULL);
1700 }
1701 KASSERT(tp->_t_logstate == TCP_LOG_STATE_HEAD ||
1702 tp->_t_logstate == TCP_LOG_STATE_TAIL ||
1703 tp->_t_logstate == TCP_LOG_STATE_CONTINUAL ||
1704 tp->_t_logstate == TCP_LOG_STATE_HEAD_AUTO ||
1705 tp->_t_logstate == TCP_LOG_VIA_BBPOINTS ||
1706 tp->_t_logstate == TCP_LOG_STATE_TAIL_AUTO,
1707 ("%s called with unexpected tp->_t_logstate (%d)", __func__,
1708 tp->_t_logstate));
1709
1710 /*
1711 * Get the serial number. We do this early so it will
1712 * increment even if we end up skipping the log entry for some
1713 * reason.
1714 */
1715 logsn = tp->t_logsn++;
1716
1717 /*
1718 * Can we get a new log entry? If so, increment the lognum counter
1719 * here.
1720 */
1721 retry:
1722 if (tp->t_lognum < tp->t_loglimit) {
1723 if ((log_entry = uma_zalloc(tcp_log_zone, M_NOWAIT)) != NULL)
1724 tp->t_lognum++;
1725 } else
1726 log_entry = NULL;
1727
1728 /* Do we need to try to reuse? */
1729 if (log_entry == NULL) {
1730 /*
1731 * Sacrifice auto-logged sessions without a log ID if
1732 * tcp_log_auto_all is false. (If they don't have a log
1733 * ID by now, it is probable that either they won't get one
1734 * or we are resource-constrained.)
1735 */
1736 if (tp->t_lib == NULL && (tp->t_flags2 & TF2_LOG_AUTO) &&
1737 !tcp_log_auto_all) {
1738 if (tcp_log_state_change(tp, TCP_LOG_STATE_CLEAR)) {
1739 #ifdef INVARIANTS
1740 panic("%s:%d: tcp_log_state_change() failed "
1741 "to set tp %p to TCP_LOG_STATE_CLEAR",
1742 __func__, __LINE__, tp);
1743 #endif
1744 tp->_t_logstate = TCP_LOG_STATE_OFF;
1745 }
1746 return (NULL);
1747 }
1748 /*
1749 * If we are in TCP_LOG_STATE_HEAD_AUTO state, try to dump
1750 * the buffers. If successful, deactivate tracing. Otherwise,
1751 * leave it active so we will retry.
1752 */
1753 if (tp->_t_logstate == TCP_LOG_STATE_HEAD_AUTO &&
1754 !tcp_log_dump_tp_logbuf(tp, "auto-dumped from head",
1755 M_NOWAIT, false)) {
1756 tp->_t_logstate = TCP_LOG_STATE_OFF;
1757 return(NULL);
1758 } else if ((tp->_t_logstate == TCP_LOG_STATE_CONTINUAL) &&
1759 !tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
1760 M_NOWAIT, false)) {
1761 if (attempt_count == 0) {
1762 attempt_count++;
1763 goto retry;
1764 }
1765 #ifdef TCPLOG_DEBUG_COUNTERS
1766 counter_u64_add(tcp_log_que_fail4, 1);
1767 #endif
1768 return(NULL);
1769
1770 } else if ((tp->_t_logstate == TCP_LOG_VIA_BBPOINTS) &&
1771 !tcp_log_dump_tp_logbuf(tp, "auto-dumped from bbpoints",
1772 M_NOWAIT, false)) {
1773 if (attempt_count == 0) {
1774 attempt_count++;
1775 goto retry;
1776 }
1777 #ifdef TCPLOG_DEBUG_COUNTERS
1778 counter_u64_add(tcp_log_que_fail4, 1);
1779 #endif
1780 return(NULL);
1781 } else if (tp->_t_logstate == TCP_LOG_STATE_HEAD_AUTO)
1782 return(NULL);
1783
1784 /* If in HEAD state, just deactivate the tracing and return. */
1785 if (tp->_t_logstate == TCP_LOG_STATE_HEAD) {
1786 tp->_t_logstate = TCP_LOG_STATE_OFF;
1787 return(NULL);
1788 }
1789 /*
1790 * Get a buffer to reuse. If that fails, just give up.
1791 * (We can't log anything without a buffer in which to
1792 * put it.)
1793 *
1794 * Note that we don't change the t_lognum counter
1795 * here. Because we are re-using the buffer, the total
1796 * number won't change.
1797 */
1798 if ((log_entry = STAILQ_FIRST(&tp->t_logs)) == NULL)
1799 return(NULL);
1800 STAILQ_REMOVE_HEAD(&tp->t_logs, tlm_queue);
1801 tcp_log_entry_refcnt_rem(log_entry);
1802 }
1803
1804 KASSERT(log_entry != NULL,
1805 ("%s: log_entry unexpectedly NULL", __func__));
1806
1807 /* Extract the log buffer and verbose buffer pointers. */
1808 log_buf = &log_entry->tlm_buf;
1809 log_verbose = &log_entry->tlm_v;
1810
1811 /* Basic entries. */
1812 if (itv == NULL)
1813 microuptime(&log_buf->tlb_tv);
1814 else
1815 memcpy(&log_buf->tlb_tv, itv, sizeof(struct timeval));
1816 log_buf->tlb_ticks = ticks;
1817 log_buf->tlb_sn = logsn;
1818 log_buf->tlb_stackid = tp->t_fb->tfb_id;
1819 log_buf->tlb_eventid = eventid;
1820 log_buf->tlb_eventflags = 0;
1821 log_buf->tlb_errno = errornum;
1822
1823 /* Socket buffers */
1824 if (rxbuf != NULL) {
1825 log_buf->tlb_eventflags |= TLB_FLAG_RXBUF;
1826 log_buf->tlb_rxbuf.tls_sb_acc = rxbuf->sb_acc;
1827 log_buf->tlb_rxbuf.tls_sb_ccc = rxbuf->sb_ccc;
1828 log_buf->tlb_rxbuf.tls_sb_spare = 0;
1829 } else {
1830 log_buf->tlb_rxbuf.tls_sb_acc = 0;
1831 log_buf->tlb_rxbuf.tls_sb_ccc = 0;
1832 }
1833 if (txbuf != NULL) {
1834 log_buf->tlb_eventflags |= TLB_FLAG_TXBUF;
1835 log_buf->tlb_txbuf.tls_sb_acc = txbuf->sb_acc;
1836 log_buf->tlb_txbuf.tls_sb_ccc = txbuf->sb_ccc;
1837 log_buf->tlb_txbuf.tls_sb_spare = 0;
1838 } else {
1839 log_buf->tlb_txbuf.tls_sb_acc = 0;
1840 log_buf->tlb_txbuf.tls_sb_ccc = 0;
1841 }
1842 /* Copy values from tp to the log entry. */
1843 #define COPY_STAT(f) log_buf->tlb_ ## f = tp->f
1844 #define COPY_STAT_T(f) log_buf->tlb_ ## f = tp->t_ ## f
1845 COPY_STAT_T(state);
1846 COPY_STAT_T(starttime);
1847 COPY_STAT(iss);
1848 COPY_STAT_T(flags);
1849 COPY_STAT(snd_una);
1850 COPY_STAT(snd_max);
1851 COPY_STAT(snd_cwnd);
1852 COPY_STAT(snd_nxt);
1853 COPY_STAT(snd_recover);
1854 COPY_STAT(snd_wnd);
1855 COPY_STAT(snd_ssthresh);
1856 COPY_STAT_T(srtt);
1857 COPY_STAT_T(rttvar);
1858 COPY_STAT(rcv_up);
1859 COPY_STAT(rcv_adv);
1860 COPY_STAT(rcv_nxt);
1861 COPY_STAT(rcv_wnd);
1862 COPY_STAT_T(dupacks);
1863 COPY_STAT_T(segqlen);
1864 COPY_STAT(snd_numholes);
1865 COPY_STAT(snd_scale);
1866 COPY_STAT(rcv_scale);
1867 COPY_STAT_T(flags2);
1868 COPY_STAT_T(fbyte_in);
1869 COPY_STAT_T(fbyte_out);
1870 #undef COPY_STAT
1871 #undef COPY_STAT_T
1872 /* Copy stack-specific info. */
1873 if (stackinfo != NULL) {
1874 memcpy(&log_buf->tlb_stackinfo, stackinfo,
1875 sizeof(log_buf->tlb_stackinfo));
1876 log_buf->tlb_eventflags |= TLB_FLAG_STACKINFO;
1877 }
1878
1879 /* The packet */
1880 log_buf->tlb_len = len;
1881 if (th) {
1882 int optlen;
1883
1884 log_buf->tlb_eventflags |= TLB_FLAG_HDR;
1885 log_buf->tlb_th = *th;
1886 if (th_hostorder)
1887 tcp_fields_to_net(&log_buf->tlb_th);
1888 optlen = (th->th_off << 2) - sizeof (struct tcphdr);
1889 if (optlen > 0)
1890 memcpy(log_buf->tlb_opts, th + 1, optlen);
1891 } else {
1892 memset(&log_buf->tlb_th, 0, sizeof(*th));
1893 }
1894
1895 /* Verbose information */
1896 if (func != NULL) {
1897 log_buf->tlb_eventflags |= TLB_FLAG_VERBOSE;
1898 if (output_caller != NULL)
1899 strlcpy(log_verbose->tlv_snd_frm, output_caller,
1900 TCP_FUNC_LEN);
1901 else
1902 *log_verbose->tlv_snd_frm = 0;
1903 strlcpy(log_verbose->tlv_trace_func, func, TCP_FUNC_LEN);
1904 log_verbose->tlv_trace_line = line;
1905 }
1906
1907 /* Insert the new log at the tail. */
1908 STAILQ_INSERT_TAIL(&tp->t_logs, log_entry, tlm_queue);
1909 tcp_log_entry_refcnt_add(log_entry);
1910 return (log_buf);
1911 }
1912
1913 /*
1914 * Change the logging state for a TCPCB. Returns 0 on success or an
1915 * error code on failure.
1916 */
1917 int
tcp_log_state_change(struct tcpcb * tp,int state)1918 tcp_log_state_change(struct tcpcb *tp, int state)
1919 {
1920 struct tcp_log_mem *log_entry;
1921 int rv;
1922
1923 INP_WLOCK_ASSERT(tptoinpcb(tp));
1924 rv = 0;
1925 switch(state) {
1926 case TCP_LOG_STATE_CLEAR:
1927 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
1928 tcp_log_remove_log_head(tp, log_entry);
1929 /* FALLTHROUGH */
1930
1931 case TCP_LOG_STATE_OFF:
1932 tp->_t_logstate = TCP_LOG_STATE_OFF;
1933 break;
1934
1935 case TCP_LOG_STATE_TAIL:
1936 case TCP_LOG_STATE_HEAD:
1937 case TCP_LOG_STATE_CONTINUAL:
1938 case TCP_LOG_VIA_BBPOINTS:
1939 case TCP_LOG_STATE_HEAD_AUTO:
1940 case TCP_LOG_STATE_TAIL_AUTO:
1941 /*
1942 * When the RATIO_OFF state is set for the bucket, the log ID
1943 * this tp is associated with has been probabilistically opted
1944 * out of logging per tcp_log_apply_ratio().
1945 */
1946 if (tp->t_lib == NULL ||
1947 tp->t_lib->tlb_logstate != TCP_LOG_STATE_RATIO_OFF) {
1948 tp->_t_logstate = state;
1949 } else {
1950 rv = ECANCELED;
1951 tp->_t_logstate = TCP_LOG_STATE_OFF;
1952 }
1953 break;
1954
1955 default:
1956 return (EINVAL);
1957 }
1958 if (tcp_disable_all_bb_logs) {
1959 /* We are prohibited from doing any logs */
1960 tp->_t_logstate = TCP_LOG_STATE_OFF;
1961 rv = EBUSY;
1962 }
1963 tp->t_flags2 &= ~(TF2_LOG_AUTO);
1964
1965 return (rv);
1966 }
1967
1968 /* If tcp_drain() is called, flush half the log entries. */
1969 void
tcp_log_drain(struct tcpcb * tp)1970 tcp_log_drain(struct tcpcb *tp)
1971 {
1972 struct tcp_log_mem *log_entry, *next;
1973 int target, skip;
1974
1975 INP_WLOCK_ASSERT(tptoinpcb(tp));
1976 if ((target = tp->t_lognum / 2) == 0)
1977 return;
1978
1979 /*
1980 * XXXRRS: At this I don't think this is wise that
1981 * we do this. All that a drain call means is that
1982 * we are hitting one of the system mbuf limits. BB
1983 * logging, or freeing of them, will not create any
1984 * more mbufs and really has nothing to do with
1985 * the system running out of mbufs. For now I
1986 * am changing this to free any "AUTO" by dumping
1987 * them out. But this should either be changed
1988 * so that it gets called when we hit the BB limit
1989 * or it should just not get called (one of the two)
1990 * since I don't think the mbuf <-> BB log cleanup
1991 * is the right thing to do here.
1992 */
1993 /*
1994 * If we are logging the "head" packets, we want to discard
1995 * from the tail of the queue. Otherwise, we want to discard
1996 * from the head.
1997 */
1998 if (tp->_t_logstate == TCP_LOG_STATE_HEAD) {
1999 skip = tp->t_lognum - target;
2000 STAILQ_FOREACH(log_entry, &tp->t_logs, tlm_queue)
2001 if (!--skip)
2002 break;
2003 KASSERT(log_entry != NULL,
2004 ("%s: skipped through all entries!", __func__));
2005 if (log_entry == NULL)
2006 return;
2007 while ((next = STAILQ_NEXT(log_entry, tlm_queue)) != NULL) {
2008 STAILQ_REMOVE_AFTER(&tp->t_logs, log_entry, tlm_queue);
2009 tcp_log_entry_refcnt_rem(next);
2010 tcp_log_remove_log_cleanup(tp, next);
2011 #ifdef INVARIANTS
2012 target--;
2013 #endif
2014 }
2015 KASSERT(target == 0,
2016 ("%s: After removing from tail, target was %d", __func__,
2017 target));
2018 } else if (tp->_t_logstate == TCP_LOG_STATE_HEAD_AUTO) {
2019 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from head at drain",
2020 M_NOWAIT, false);
2021 } else if (tp->_t_logstate == TCP_LOG_STATE_TAIL_AUTO) {
2022 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from tail at drain",
2023 M_NOWAIT, false);
2024 } else if (tp->_t_logstate == TCP_LOG_VIA_BBPOINTS) {
2025 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from bbpoints",
2026 M_NOWAIT, false);
2027 } else if (tp->_t_logstate == TCP_LOG_STATE_CONTINUAL) {
2028 (void)tcp_log_dump_tp_logbuf(tp, "auto-dumped from continual",
2029 M_NOWAIT, false);
2030 } else {
2031 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL &&
2032 target--)
2033 tcp_log_remove_log_head(tp, log_entry);
2034 KASSERT(target <= 0,
2035 ("%s: After removing from head, target was %d", __func__,
2036 target));
2037 KASSERT(tp->t_lognum > 0,
2038 ("%s: After removing from head, tp->t_lognum was %d",
2039 __func__, target));
2040 KASSERT(log_entry != NULL,
2041 ("%s: After removing from head, the tailq was empty",
2042 __func__));
2043 }
2044 }
2045
2046 static inline int
tcp_log_copyout(struct sockopt * sopt,void * src,void * dst,size_t len)2047 tcp_log_copyout(struct sockopt *sopt, void *src, void *dst, size_t len)
2048 {
2049
2050 if (sopt->sopt_td != NULL)
2051 return (copyout(src, dst, len));
2052 bcopy(src, dst, len);
2053 return (0);
2054 }
2055
2056 static int
tcp_log_logs_to_buf(struct sockopt * sopt,struct tcp_log_stailq * log_tailqp,struct tcp_log_buffer ** end,int count)2057 tcp_log_logs_to_buf(struct sockopt *sopt, struct tcp_log_stailq *log_tailqp,
2058 struct tcp_log_buffer **end, int count)
2059 {
2060 struct tcp_log_buffer *out_entry;
2061 struct tcp_log_mem *log_entry;
2062 size_t entrysize;
2063 int error;
2064 #ifdef INVARIANTS
2065 int orig_count = count;
2066 #endif
2067
2068 /* Copy the data out. */
2069 error = 0;
2070 out_entry = (struct tcp_log_buffer *) sopt->sopt_val;
2071 STAILQ_FOREACH(log_entry, log_tailqp, tlm_queue) {
2072 count--;
2073 KASSERT(count >= 0,
2074 ("%s:%d: Exceeded expected count (%d) processing list %p",
2075 __func__, __LINE__, orig_count, log_tailqp));
2076
2077 #ifdef TCPLOG_DEBUG_COUNTERS
2078 counter_u64_add(tcp_log_que_copyout, 1);
2079 #endif
2080
2081 /*
2082 * Skip copying out the header if it isn't present.
2083 * Instead, copy out zeros (to ensure we don't leak info).
2084 * TODO: Make sure we truly do zero everything we don't
2085 * explicitly set.
2086 */
2087 if (log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_HDR)
2088 entrysize = sizeof(struct tcp_log_buffer);
2089 else
2090 entrysize = offsetof(struct tcp_log_buffer, tlb_th);
2091 error = tcp_log_copyout(sopt, &log_entry->tlm_buf, out_entry,
2092 entrysize);
2093 if (error)
2094 break;
2095 if (!(log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_HDR)) {
2096 error = tcp_log_copyout(sopt, zerobuf,
2097 ((uint8_t *)out_entry) + entrysize,
2098 sizeof(struct tcp_log_buffer) - entrysize);
2099 }
2100
2101 /*
2102 * Copy out the verbose bit, if needed. Either way,
2103 * increment the output pointer the correct amount.
2104 */
2105 if (log_entry->tlm_buf.tlb_eventflags & TLB_FLAG_VERBOSE) {
2106 error = tcp_log_copyout(sopt, &log_entry->tlm_v,
2107 out_entry->tlb_verbose,
2108 sizeof(struct tcp_log_verbose));
2109 if (error)
2110 break;
2111 out_entry = (struct tcp_log_buffer *)
2112 (((uint8_t *) (out_entry + 1)) +
2113 sizeof(struct tcp_log_verbose));
2114 } else
2115 out_entry++;
2116 }
2117 *end = out_entry;
2118 KASSERT(error || count == 0,
2119 ("%s:%d: Less than expected count (%d) processing list %p"
2120 " (%d remain)", __func__, __LINE__, orig_count,
2121 log_tailqp, count));
2122
2123 return (error);
2124 }
2125
2126 /*
2127 * Copy out the buffer. Note that we do incremental copying, so
2128 * sooptcopyout() won't work. However, the goal is to produce the same
2129 * end result as if we copied in the entire user buffer, updated it,
2130 * and then used sooptcopyout() to copy it out.
2131 *
2132 * NOTE: This should be called with a write lock on the PCB; however,
2133 * the function will drop it after it extracts the data from the TCPCB.
2134 */
2135 int
tcp_log_getlogbuf(struct sockopt * sopt,struct tcpcb * tp)2136 tcp_log_getlogbuf(struct sockopt *sopt, struct tcpcb *tp)
2137 {
2138 struct tcp_log_stailq log_tailq;
2139 struct tcp_log_mem *log_entry, *log_next;
2140 struct tcp_log_buffer *out_entry;
2141 struct inpcb *inp = tptoinpcb(tp);
2142 size_t outsize, entrysize;
2143 int error, outnum;
2144
2145 INP_WLOCK_ASSERT(inp);
2146
2147 /*
2148 * Determine which log entries will fit in the buffer. As an
2149 * optimization, skip this if all the entries will clearly fit
2150 * in the buffer. (However, get an exact size if we are using
2151 * INVARIANTS.)
2152 */
2153 #ifndef INVARIANTS
2154 if (sopt->sopt_valsize / (sizeof(struct tcp_log_buffer) +
2155 sizeof(struct tcp_log_verbose)) >= tp->t_lognum) {
2156 log_entry = STAILQ_LAST(&tp->t_logs, tcp_log_mem, tlm_queue);
2157 log_next = NULL;
2158 outsize = 0;
2159 outnum = tp->t_lognum;
2160 } else {
2161 #endif
2162 outsize = outnum = 0;
2163 log_entry = NULL;
2164 STAILQ_FOREACH(log_next, &tp->t_logs, tlm_queue) {
2165 entrysize = sizeof(struct tcp_log_buffer);
2166 if (log_next->tlm_buf.tlb_eventflags &
2167 TLB_FLAG_VERBOSE)
2168 entrysize += sizeof(struct tcp_log_verbose);
2169 if ((sopt->sopt_valsize - outsize) < entrysize)
2170 break;
2171 outsize += entrysize;
2172 outnum++;
2173 log_entry = log_next;
2174 }
2175 KASSERT(outsize <= sopt->sopt_valsize,
2176 ("%s: calculated output size (%zu) greater than available"
2177 "space (%zu)", __func__, outsize, sopt->sopt_valsize));
2178 #ifndef INVARIANTS
2179 }
2180 #endif
2181
2182 /*
2183 * Copy traditional sooptcopyout() behavior: if sopt->sopt_val
2184 * is NULL, silently skip the copy. However, in this case, we
2185 * will leave the list alone and return. Functionally, this
2186 * gives userspace a way to poll for an approximate buffer
2187 * size they will need to get the log entries.
2188 */
2189 if (sopt->sopt_val == NULL) {
2190 INP_WUNLOCK(inp);
2191 if (outsize == 0) {
2192 outsize = outnum * (sizeof(struct tcp_log_buffer) +
2193 sizeof(struct tcp_log_verbose));
2194 }
2195 if (sopt->sopt_valsize > outsize)
2196 sopt->sopt_valsize = outsize;
2197 return (0);
2198 }
2199
2200 /*
2201 * Break apart the list. We'll save the ones we want to copy
2202 * out locally and remove them from the TCPCB list. We can
2203 * then drop the INPCB lock while we do the copyout.
2204 *
2205 * There are roughly three cases:
2206 * 1. There was nothing to copy out. That's easy: drop the
2207 * lock and return.
2208 * 2. We are copying out the entire list. Again, that's easy:
2209 * move the whole list.
2210 * 3. We are copying out a partial list. That's harder. We
2211 * need to update the list book-keeping entries.
2212 */
2213 if (log_entry != NULL && log_next == NULL) {
2214 /* Move entire list. */
2215 KASSERT(outnum == tp->t_lognum,
2216 ("%s:%d: outnum (%d) should match tp->t_lognum (%d)",
2217 __func__, __LINE__, outnum, tp->t_lognum));
2218 log_tailq = tp->t_logs;
2219 tp->t_lognum = 0;
2220 STAILQ_INIT(&tp->t_logs);
2221 } else if (log_entry != NULL) {
2222 /* Move partial list. */
2223 KASSERT(outnum < tp->t_lognum,
2224 ("%s:%d: outnum (%d) not less than tp->t_lognum (%d)",
2225 __func__, __LINE__, outnum, tp->t_lognum));
2226 STAILQ_FIRST(&log_tailq) = STAILQ_FIRST(&tp->t_logs);
2227 STAILQ_FIRST(&tp->t_logs) = STAILQ_NEXT(log_entry, tlm_queue);
2228 KASSERT(STAILQ_NEXT(log_entry, tlm_queue) != NULL,
2229 ("%s:%d: tp->t_logs is unexpectedly shorter than expected"
2230 "(tp: %p, log_tailq: %p, outnum: %d, tp->t_lognum: %d)",
2231 __func__, __LINE__, tp, &log_tailq, outnum, tp->t_lognum));
2232 STAILQ_NEXT(log_entry, tlm_queue) = NULL;
2233 log_tailq.stqh_last = &STAILQ_NEXT(log_entry, tlm_queue);
2234 tp->t_lognum -= outnum;
2235 } else
2236 STAILQ_INIT(&log_tailq);
2237
2238 /* Drop the PCB lock. */
2239 INP_WUNLOCK(inp);
2240
2241 /* Copy the data out. */
2242 error = tcp_log_logs_to_buf(sopt, &log_tailq, &out_entry, outnum);
2243
2244 if (error) {
2245 /* Restore list */
2246 INP_WLOCK(inp);
2247 if ((inp->inp_flags & INP_DROPPED) == 0) {
2248 tp = intotcpcb(inp);
2249
2250 /* Merge the two lists. */
2251 STAILQ_CONCAT(&log_tailq, &tp->t_logs);
2252 tp->t_logs = log_tailq;
2253 tp->t_lognum += outnum;
2254 }
2255 INP_WUNLOCK(inp);
2256 } else {
2257 /* Sanity check entries */
2258 KASSERT(((caddr_t)out_entry - (caddr_t)sopt->sopt_val) ==
2259 outsize, ("%s: Actual output size (%zu) != "
2260 "calculated output size (%zu)", __func__,
2261 (size_t)((caddr_t)out_entry - (caddr_t)sopt->sopt_val),
2262 outsize));
2263
2264 /* Free the entries we just copied out. */
2265 STAILQ_FOREACH_SAFE(log_entry, &log_tailq, tlm_queue, log_next) {
2266 tcp_log_entry_refcnt_rem(log_entry);
2267 uma_zfree(tcp_log_zone, log_entry);
2268 }
2269 }
2270
2271 sopt->sopt_valsize = (size_t)((caddr_t)out_entry -
2272 (caddr_t)sopt->sopt_val);
2273 return (error);
2274 }
2275
2276 static void
tcp_log_free_queue(struct tcp_log_dev_queue * param)2277 tcp_log_free_queue(struct tcp_log_dev_queue *param)
2278 {
2279 struct tcp_log_dev_log_queue *entry;
2280
2281 KASSERT(param != NULL, ("%s: called with NULL param", __func__));
2282 if (param == NULL)
2283 return;
2284
2285 entry = (struct tcp_log_dev_log_queue *)param;
2286
2287 /* Free the entries. */
2288 tcp_log_free_entries(&entry->tldl_entries, &entry->tldl_count);
2289
2290 /* Free the buffer, if it is allocated. */
2291 if (entry->tldl_common.tldq_buf != NULL)
2292 free(entry->tldl_common.tldq_buf, M_TCPLOGDEV);
2293
2294 /* Free the queue entry. */
2295 free(entry, M_TCPLOGDEV);
2296 }
2297
2298 static struct tcp_log_common_header *
tcp_log_expandlogbuf(struct tcp_log_dev_queue * param)2299 tcp_log_expandlogbuf(struct tcp_log_dev_queue *param)
2300 {
2301 struct tcp_log_dev_log_queue *entry;
2302 struct tcp_log_header *hdr;
2303 uint8_t *end;
2304 struct sockopt sopt;
2305 int error;
2306
2307 entry = (struct tcp_log_dev_log_queue *)param;
2308
2309 /* Take a worst-case guess at space needs. */
2310 sopt.sopt_valsize = sizeof(struct tcp_log_header) +
2311 entry->tldl_count * (sizeof(struct tcp_log_buffer) +
2312 sizeof(struct tcp_log_verbose));
2313 hdr = malloc(sopt.sopt_valsize, M_TCPLOGDEV, M_NOWAIT);
2314 if (hdr == NULL) {
2315 #ifdef TCPLOG_DEBUG_COUNTERS
2316 counter_u64_add(tcp_log_que_fail5, entry->tldl_count);
2317 #endif
2318 return (NULL);
2319 }
2320 sopt.sopt_val = hdr + 1;
2321 sopt.sopt_valsize -= sizeof(struct tcp_log_header);
2322 sopt.sopt_td = NULL;
2323
2324 error = tcp_log_logs_to_buf(&sopt, &entry->tldl_entries,
2325 (struct tcp_log_buffer **)&end, entry->tldl_count);
2326 if (error) {
2327 free(hdr, M_TCPLOGDEV);
2328 return (NULL);
2329 }
2330
2331 /* Free the entries. */
2332 tcp_log_free_entries(&entry->tldl_entries, &entry->tldl_count);
2333 entry->tldl_count = 0;
2334
2335 memset(hdr, 0, sizeof(struct tcp_log_header));
2336 hdr->tlh_version = TCP_LOG_BUF_VER;
2337 hdr->tlh_type = TCP_LOG_DEV_TYPE_BBR;
2338 hdr->tlh_length = end - (uint8_t *)hdr;
2339 hdr->tlh_ie = entry->tldl_ie;
2340 hdr->tlh_af = entry->tldl_af;
2341 getboottime(&hdr->tlh_offset);
2342 strlcpy(hdr->tlh_id, entry->tldl_id, TCP_LOG_ID_LEN);
2343 strlcpy(hdr->tlh_tag, entry->tldl_tag, TCP_LOG_TAG_LEN);
2344 strlcpy(hdr->tlh_reason, entry->tldl_reason, TCP_LOG_REASON_LEN);
2345 return ((struct tcp_log_common_header *)hdr);
2346 }
2347
2348 /*
2349 * Queue the tcpcb's log buffer for transmission via the log buffer facility.
2350 *
2351 * NOTE: This should be called with a write lock on the PCB.
2352 *
2353 * how should be M_WAITOK or M_NOWAIT. If M_WAITOK, the function will drop
2354 * and reacquire the INP lock if it needs to do so.
2355 *
2356 * If force is false, this will only dump auto-logged sessions if
2357 * tcp_log_auto_all is true or if there is a log ID defined for the session.
2358 */
2359 int
tcp_log_dump_tp_logbuf(struct tcpcb * tp,char * reason,int how,bool force)2360 tcp_log_dump_tp_logbuf(struct tcpcb *tp, char *reason, int how, bool force)
2361 {
2362 struct tcp_log_dev_log_queue *entry;
2363 struct inpcb *inp = tptoinpcb(tp);
2364 #ifdef TCPLOG_DEBUG_COUNTERS
2365 int num_entries;
2366 #endif
2367
2368 INP_WLOCK_ASSERT(inp);
2369
2370 /* If there are no log entries, there is nothing to do. */
2371 if (tp->t_lognum == 0)
2372 return (0);
2373
2374 /* Check for a log ID. */
2375 if (tp->t_lib == NULL && (tp->t_flags2 & TF2_LOG_AUTO) &&
2376 !tcp_log_auto_all && !force) {
2377 struct tcp_log_mem *log_entry;
2378
2379 /*
2380 * We needed a log ID and none was found. Free the log entries
2381 * and return success. Also, cancel further logging. If the
2382 * session doesn't have a log ID by now, we'll assume it isn't
2383 * going to get one.
2384 */
2385 while ((log_entry = STAILQ_FIRST(&tp->t_logs)) != NULL)
2386 tcp_log_remove_log_head(tp, log_entry);
2387 KASSERT(tp->t_lognum == 0,
2388 ("%s: After freeing entries, tp->t_lognum=%d (expected 0)",
2389 __func__, tp->t_lognum));
2390 tp->_t_logstate = TCP_LOG_STATE_OFF;
2391 return (0);
2392 }
2393
2394 /*
2395 * Allocate memory. If we must wait, we'll need to drop the locks
2396 * and reacquire them (and do all the related business that goes
2397 * along with that).
2398 */
2399 entry = malloc(sizeof(struct tcp_log_dev_log_queue), M_TCPLOGDEV,
2400 M_NOWAIT);
2401 if (entry == NULL && (how & M_NOWAIT)) {
2402 #ifdef TCPLOG_DEBUG_COUNTERS
2403 counter_u64_add(tcp_log_que_fail3, 1);
2404 #endif
2405 return (ENOBUFS);
2406 }
2407 if (entry == NULL) {
2408 INP_WUNLOCK(inp);
2409 entry = malloc(sizeof(struct tcp_log_dev_log_queue),
2410 M_TCPLOGDEV, M_WAITOK);
2411 INP_WLOCK(inp);
2412 /*
2413 * Note that this check is slightly overly-restrictive in
2414 * that the TCB can survive either of these events.
2415 * However, there is currently not a good way to ensure
2416 * that is the case. So, if we hit this M_WAIT path, we
2417 * may end up dropping some entries. That seems like a
2418 * small price to pay for safety.
2419 */
2420 if (inp->inp_flags & INP_DROPPED) {
2421 free(entry, M_TCPLOGDEV);
2422 #ifdef TCPLOG_DEBUG_COUNTERS
2423 counter_u64_add(tcp_log_que_fail2, 1);
2424 #endif
2425 return (ECONNRESET);
2426 }
2427 tp = intotcpcb(inp);
2428 if (tp->t_lognum == 0) {
2429 free(entry, M_TCPLOGDEV);
2430 return (0);
2431 }
2432 }
2433
2434 /* Fill in the unique parts of the queue entry. */
2435 if (tp->t_lib != NULL) {
2436 strlcpy(entry->tldl_id, tp->t_lib->tlb_id, TCP_LOG_ID_LEN);
2437 strlcpy(entry->tldl_tag, tp->t_lib->tlb_tag, TCP_LOG_TAG_LEN);
2438 } else {
2439 strlcpy(entry->tldl_id, "UNKNOWN", TCP_LOG_ID_LEN);
2440 strlcpy(entry->tldl_tag, "UNKNOWN", TCP_LOG_TAG_LEN);
2441 }
2442 if (reason != NULL)
2443 strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN);
2444 else
2445 strlcpy(entry->tldl_reason, "UNKNOWN", TCP_LOG_REASON_LEN);
2446 entry->tldl_ie = inp->inp_inc.inc_ie;
2447 if (inp->inp_inc.inc_flags & INC_ISIPV6)
2448 entry->tldl_af = AF_INET6;
2449 else
2450 entry->tldl_af = AF_INET;
2451 entry->tldl_entries = tp->t_logs;
2452 entry->tldl_count = tp->t_lognum;
2453
2454 /* Fill in the common parts of the queue entry. */
2455 entry->tldl_common.tldq_buf = NULL;
2456 entry->tldl_common.tldq_xform = tcp_log_expandlogbuf;
2457 entry->tldl_common.tldq_dtor = tcp_log_free_queue;
2458
2459 /* Clear the log data from the TCPCB. */
2460 #ifdef TCPLOG_DEBUG_COUNTERS
2461 num_entries = tp->t_lognum;
2462 #endif
2463 tp->t_lognum = 0;
2464 STAILQ_INIT(&tp->t_logs);
2465
2466 /* Add the entry. If no one is listening, free the entry. */
2467 if (tcp_log_dev_add_log((struct tcp_log_dev_queue *)entry)) {
2468 tcp_log_free_queue((struct tcp_log_dev_queue *)entry);
2469 #ifdef TCPLOG_DEBUG_COUNTERS
2470 counter_u64_add(tcp_log_que_fail1, num_entries);
2471 } else {
2472 counter_u64_add(tcp_log_queued, num_entries);
2473 #endif
2474 }
2475 return (0);
2476 }
2477
2478 /*
2479 * Queue the log_id_node's log buffers for transmission via the log buffer
2480 * facility.
2481 *
2482 * NOTE: This should be called with the bucket locked and referenced.
2483 *
2484 * how should be M_WAITOK or M_NOWAIT. If M_WAITOK, the function will drop
2485 * and reacquire the bucket lock if it needs to do so. (The caller must
2486 * ensure that the tln is no longer on any lists so no one else will mess
2487 * with this while the lock is dropped!)
2488 */
2489 static int
tcp_log_dump_node_logbuf(struct tcp_log_id_node * tln,char * reason,int how)2490 tcp_log_dump_node_logbuf(struct tcp_log_id_node *tln, char *reason, int how)
2491 {
2492 struct tcp_log_dev_log_queue *entry;
2493 struct tcp_log_id_bucket *tlb;
2494
2495 tlb = tln->tln_bucket;
2496 TCPID_BUCKET_LOCK_ASSERT(tlb);
2497 KASSERT(tlb->tlb_refcnt > 0,
2498 ("%s:%d: Called with unreferenced bucket (tln=%p, tlb=%p)",
2499 __func__, __LINE__, tln, tlb));
2500 KASSERT(tln->tln_closed,
2501 ("%s:%d: Called for node with tln_closed==false (tln=%p)",
2502 __func__, __LINE__, tln));
2503
2504 /* If there are no log entries, there is nothing to do. */
2505 if (tln->tln_count == 0)
2506 return (0);
2507
2508 /*
2509 * Allocate memory. If we must wait, we'll need to drop the locks
2510 * and reacquire them (and do all the related business that goes
2511 * along with that).
2512 */
2513 entry = malloc(sizeof(struct tcp_log_dev_log_queue), M_TCPLOGDEV,
2514 M_NOWAIT);
2515 if (entry == NULL && (how & M_NOWAIT))
2516 return (ENOBUFS);
2517 if (entry == NULL) {
2518 TCPID_BUCKET_UNLOCK(tlb);
2519 entry = malloc(sizeof(struct tcp_log_dev_log_queue),
2520 M_TCPLOGDEV, M_WAITOK);
2521 TCPID_BUCKET_LOCK(tlb);
2522 }
2523
2524 /* Fill in the common parts of the queue entry.. */
2525 entry->tldl_common.tldq_buf = NULL;
2526 entry->tldl_common.tldq_xform = tcp_log_expandlogbuf;
2527 entry->tldl_common.tldq_dtor = tcp_log_free_queue;
2528
2529 /* Fill in the unique parts of the queue entry. */
2530 strlcpy(entry->tldl_id, tlb->tlb_id, TCP_LOG_ID_LEN);
2531 strlcpy(entry->tldl_tag, tlb->tlb_tag, TCP_LOG_TAG_LEN);
2532 if (reason != NULL)
2533 strlcpy(entry->tldl_reason, reason, TCP_LOG_REASON_LEN);
2534 else
2535 strlcpy(entry->tldl_reason, "UNKNOWN", TCP_LOG_REASON_LEN);
2536 entry->tldl_ie = tln->tln_ie;
2537 entry->tldl_entries = tln->tln_entries;
2538 entry->tldl_count = tln->tln_count;
2539 entry->tldl_af = tln->tln_af;
2540
2541 /* Add the entry. If no one is listening, free the entry. */
2542 if (tcp_log_dev_add_log((struct tcp_log_dev_queue *)entry))
2543 tcp_log_free_queue((struct tcp_log_dev_queue *)entry);
2544
2545 return (0);
2546 }
2547
2548 /*
2549 * Queue the log buffers for all sessions in a bucket for transmissions via
2550 * the log buffer facility.
2551 *
2552 * NOTE: This should be called with a locked bucket; however, the function
2553 * will drop the lock.
2554 */
2555 #define LOCAL_SAVE 10
2556 static void
tcp_log_dumpbucketlogs(struct tcp_log_id_bucket * tlb,char * reason)2557 tcp_log_dumpbucketlogs(struct tcp_log_id_bucket *tlb, char *reason)
2558 {
2559 struct tcp_log_id_node local_entries[LOCAL_SAVE];
2560 struct inpcb *inp;
2561 struct tcpcb *tp;
2562 struct tcp_log_id_node *cur_tln, *prev_tln, *tmp_tln;
2563 int i, num_local_entries, tree_locked;
2564 bool expireq_locked;
2565
2566 TCPID_BUCKET_LOCK_ASSERT(tlb);
2567
2568 /*
2569 * Take a reference on the bucket to keep it from disappearing until
2570 * we are done.
2571 */
2572 TCPID_BUCKET_REF(tlb);
2573
2574 /*
2575 * We'll try to create these without dropping locks. However, we
2576 * might very well need to drop locks to get memory. If that's the
2577 * case, we'll save up to 10 on the stack, and sacrifice the rest.
2578 * (Otherwise, we need to worry about finding our place again in a
2579 * potentially changed list. It just doesn't seem worth the trouble
2580 * to do that.
2581 */
2582 expireq_locked = false;
2583 num_local_entries = 0;
2584 prev_tln = NULL;
2585 tree_locked = TREE_UNLOCKED;
2586 SLIST_FOREACH_SAFE(cur_tln, &tlb->tlb_head, tln_list, tmp_tln) {
2587 /*
2588 * If this isn't associated with a TCPCB, we can pull it off
2589 * the list now. We need to be careful that the expire timer
2590 * hasn't already taken ownership (tln_expiretime == SBT_MAX).
2591 * If so, we let the expire timer code free the data.
2592 */
2593 if (cur_tln->tln_closed) {
2594 no_inp:
2595 /*
2596 * Get the expireq lock so we can get a consistent
2597 * read of tln_expiretime and so we can remove this
2598 * from the expireq.
2599 */
2600 if (!expireq_locked) {
2601 TCPLOG_EXPIREQ_LOCK();
2602 expireq_locked = true;
2603 }
2604
2605 /*
2606 * We ignore entries with tln_expiretime == SBT_MAX.
2607 * The expire timer code already owns those.
2608 */
2609 KASSERT(cur_tln->tln_expiretime > (sbintime_t) 0,
2610 ("%s:%d: node on the expire queue without positive "
2611 "expire time", __func__, __LINE__));
2612 if (cur_tln->tln_expiretime == SBT_MAX) {
2613 prev_tln = cur_tln;
2614 continue;
2615 }
2616
2617 /* Remove the entry from the expireq. */
2618 STAILQ_REMOVE(&tcp_log_expireq_head, cur_tln,
2619 tcp_log_id_node, tln_expireq);
2620
2621 /* Remove the entry from the bucket. */
2622 if (prev_tln != NULL)
2623 SLIST_REMOVE_AFTER(prev_tln, tln_list);
2624 else
2625 SLIST_REMOVE_HEAD(&tlb->tlb_head, tln_list);
2626
2627 /*
2628 * Drop the INP and bucket reference counts. Due to
2629 * lock-ordering rules, we need to drop the expire
2630 * queue lock.
2631 */
2632 TCPLOG_EXPIREQ_UNLOCK();
2633 expireq_locked = false;
2634
2635 /* Drop the INP reference. */
2636 INP_WLOCK(cur_tln->tln_inp);
2637 if (!in_pcbrele_wlocked(cur_tln->tln_inp))
2638 INP_WUNLOCK(cur_tln->tln_inp);
2639
2640 if (tcp_log_unref_bucket(tlb, &tree_locked, NULL)) {
2641 #ifdef INVARIANTS
2642 panic("%s: Bucket refcount unexpectedly 0.",
2643 __func__);
2644 #endif
2645 /*
2646 * Recover as best we can: free the entry we
2647 * own.
2648 */
2649 tcp_log_free_entries(&cur_tln->tln_entries,
2650 &cur_tln->tln_count);
2651 uma_zfree(tcp_log_id_node_zone, cur_tln);
2652 goto done;
2653 }
2654
2655 if (tcp_log_dump_node_logbuf(cur_tln, reason,
2656 M_NOWAIT)) {
2657 /*
2658 * If we have sapce, save the entries locally.
2659 * Otherwise, free them.
2660 */
2661 if (num_local_entries < LOCAL_SAVE) {
2662 local_entries[num_local_entries] =
2663 *cur_tln;
2664 num_local_entries++;
2665 } else {
2666 tcp_log_free_entries(
2667 &cur_tln->tln_entries,
2668 &cur_tln->tln_count);
2669 }
2670 }
2671
2672 /* No matter what, we are done with the node now. */
2673 uma_zfree(tcp_log_id_node_zone, cur_tln);
2674
2675 /*
2676 * Because we removed this entry from the list, prev_tln
2677 * (which tracks the previous entry still on the tlb
2678 * list) remains unchanged.
2679 */
2680 continue;
2681 }
2682
2683 /*
2684 * If we get to this point, the session data is still held in
2685 * the TCPCB. So, we need to pull the data out of that.
2686 *
2687 * We will need to drop the expireq lock so we can lock the INP.
2688 * We can then try to extract the data the "easy" way. If that
2689 * fails, we'll save the log entries for later.
2690 */
2691 if (expireq_locked) {
2692 TCPLOG_EXPIREQ_UNLOCK();
2693 expireq_locked = false;
2694 }
2695
2696 /* Lock the INP and then re-check the state. */
2697 inp = cur_tln->tln_inp;
2698 INP_WLOCK(inp);
2699 /*
2700 * If we caught this while it was transitioning, the data
2701 * might have moved from the TCPCB to the tln (signified by
2702 * setting tln_closed to true. If so, treat this like an
2703 * inactive connection.
2704 */
2705 if (cur_tln->tln_closed) {
2706 /*
2707 * It looks like we may have caught this connection
2708 * while it was transitioning from active to inactive.
2709 * Treat this like an inactive connection.
2710 */
2711 INP_WUNLOCK(inp);
2712 goto no_inp;
2713 }
2714
2715 /*
2716 * Try to dump the data from the tp without dropping the lock.
2717 * If this fails, try to save off the data locally.
2718 */
2719 tp = cur_tln->tln_tp;
2720 if (tcp_log_dump_tp_logbuf(tp, reason, M_NOWAIT, true) &&
2721 num_local_entries < LOCAL_SAVE) {
2722 tcp_log_move_tp_to_node(tp,
2723 &local_entries[num_local_entries]);
2724 local_entries[num_local_entries].tln_closed = 1;
2725 KASSERT(local_entries[num_local_entries].tln_bucket ==
2726 tlb, ("%s: %d: bucket mismatch for node %p",
2727 __func__, __LINE__, cur_tln));
2728 num_local_entries++;
2729 }
2730
2731 INP_WUNLOCK(inp);
2732
2733 /*
2734 * We are goint to leave the current tln on the list. It will
2735 * become the previous tln.
2736 */
2737 prev_tln = cur_tln;
2738 }
2739
2740 /* Drop our locks, if any. */
2741 KASSERT(tree_locked == TREE_UNLOCKED,
2742 ("%s: %d: tree unexpectedly locked", __func__, __LINE__));
2743 switch (tree_locked) {
2744 case TREE_WLOCKED:
2745 TCPID_TREE_WUNLOCK();
2746 tree_locked = TREE_UNLOCKED;
2747 break;
2748 case TREE_RLOCKED:
2749 TCPID_TREE_RUNLOCK();
2750 tree_locked = TREE_UNLOCKED;
2751 break;
2752 }
2753 if (expireq_locked) {
2754 TCPLOG_EXPIREQ_UNLOCK();
2755 expireq_locked = false;
2756 }
2757
2758 /*
2759 * Try again for any saved entries. tcp_log_dump_node_logbuf() is
2760 * guaranteed to free the log entries within the node. And, since
2761 * the node itself is on our stack, we don't need to free it.
2762 */
2763 for (i = 0; i < num_local_entries; i++)
2764 tcp_log_dump_node_logbuf(&local_entries[i], reason, M_WAITOK);
2765
2766 /* Drop our reference. */
2767 if (!tcp_log_unref_bucket(tlb, &tree_locked, NULL))
2768 TCPID_BUCKET_UNLOCK(tlb);
2769
2770 done:
2771 /* Drop our locks, if any. */
2772 switch (tree_locked) {
2773 case TREE_WLOCKED:
2774 TCPID_TREE_WUNLOCK();
2775 break;
2776 case TREE_RLOCKED:
2777 TCPID_TREE_RUNLOCK();
2778 break;
2779 }
2780 if (expireq_locked)
2781 TCPLOG_EXPIREQ_UNLOCK();
2782 }
2783 #undef LOCAL_SAVE
2784
2785 /*
2786 * Queue the log buffers for all sessions in a bucket for transmissions via
2787 * the log buffer facility.
2788 *
2789 * NOTE: This should be called with a locked INP; however, the function
2790 * will drop the lock.
2791 */
2792 void
tcp_log_dump_tp_bucket_logbufs(struct tcpcb * tp,char * reason)2793 tcp_log_dump_tp_bucket_logbufs(struct tcpcb *tp, char *reason)
2794 {
2795 struct inpcb *inp = tptoinpcb(tp);
2796 struct tcp_log_id_bucket *tlb;
2797 int tree_locked;
2798
2799 /* Figure out our bucket and lock it. */
2800 INP_WLOCK_ASSERT(inp);
2801 tlb = tp->t_lib;
2802 if (tlb == NULL) {
2803 /*
2804 * No bucket; treat this like a request to dump a single
2805 * session's traces.
2806 */
2807 (void)tcp_log_dump_tp_logbuf(tp, reason, M_WAITOK, true);
2808 INP_WUNLOCK(inp);
2809 return;
2810 }
2811 TCPID_BUCKET_REF(tlb);
2812 INP_WUNLOCK(inp);
2813 TCPID_BUCKET_LOCK(tlb);
2814
2815 /* If we are the last reference, we have nothing more to do here. */
2816 tree_locked = TREE_UNLOCKED;
2817 if (tcp_log_unref_bucket(tlb, &tree_locked, NULL)) {
2818 switch (tree_locked) {
2819 case TREE_WLOCKED:
2820 TCPID_TREE_WUNLOCK();
2821 break;
2822 case TREE_RLOCKED:
2823 TCPID_TREE_RUNLOCK();
2824 break;
2825 }
2826 return;
2827 }
2828
2829 /* Turn this over to tcp_log_dumpbucketlogs() to finish the work. */
2830 tcp_log_dumpbucketlogs(tlb, reason);
2831 }
2832
2833 /*
2834 * Mark the end of a flow with the current stack. A stack can add
2835 * stack-specific info to this trace event by overriding this
2836 * function (see bbr_log_flowend() for example).
2837 */
2838 void
tcp_log_flowend(struct tcpcb * tp)2839 tcp_log_flowend(struct tcpcb *tp)
2840 {
2841 if (tp->_t_logstate != TCP_LOG_STATE_OFF) {
2842 struct socket *so = tptosocket(tp);
2843 TCP_LOG_EVENT(tp, NULL, &so->so_rcv, &so->so_snd,
2844 TCP_LOG_FLOWEND, 0, 0, NULL, false);
2845 }
2846 }
2847
2848 void
tcp_log_sendfile(struct socket * so,off_t offset,size_t nbytes,int flags)2849 tcp_log_sendfile(struct socket *so, off_t offset, size_t nbytes, int flags)
2850 {
2851 struct inpcb *inp;
2852 struct tcpcb *tp;
2853 #ifdef TCP_REQUEST_TRK
2854 struct tcp_sendfile_track *ent;
2855 int i, fnd;
2856 #endif
2857
2858 inp = sotoinpcb(so);
2859 KASSERT(inp != NULL, ("tcp_log_sendfile: inp == NULL"));
2860
2861 /* quick check to see if logging is enabled for this connection */
2862 tp = intotcpcb(inp);
2863 if ((inp->inp_flags & INP_DROPPED) ||
2864 (tp->_t_logstate == TCP_LOG_STATE_OFF)) {
2865 return;
2866 }
2867
2868 INP_WLOCK(inp);
2869 /* double check log state now that we have the lock */
2870 if (inp->inp_flags & INP_DROPPED)
2871 goto done;
2872 if (tp->_t_logstate != TCP_LOG_STATE_OFF) {
2873 struct timeval tv;
2874 tcp_log_eventspecific_t log;
2875
2876 microuptime(&tv);
2877 log.u_sf.offset = offset;
2878 log.u_sf.length = nbytes;
2879 log.u_sf.flags = flags;
2880
2881 TCP_LOG_EVENTP(tp, NULL,
2882 &tptosocket(tp)->so_rcv,
2883 &tptosocket(tp)->so_snd,
2884 TCP_LOG_SENDFILE, 0, 0, &log, false, &tv);
2885 }
2886 #ifdef TCP_REQUEST_TRK
2887 if (tp->t_tcpreq_req == 0) {
2888 /* No http requests to track */
2889 goto done;
2890 }
2891 fnd = 0;
2892 if (tp->t_tcpreq_closed == 0) {
2893 /* No closed end req to track */
2894 goto skip_closed_req;
2895 }
2896 for(i = 0; i < MAX_TCP_TRK_REQ; i++) {
2897 /* Lets see if this one can be found */
2898 ent = &tp->t_tcpreq_info[i];
2899 if (ent->flags == TCP_TRK_TRACK_FLG_EMPTY) {
2900 /* Not used */
2901 continue;
2902 }
2903 if (ent->flags & TCP_TRK_TRACK_FLG_OPEN) {
2904 /* This pass does not consider open requests */
2905 continue;
2906 }
2907 if (ent->flags & TCP_TRK_TRACK_FLG_COMP) {
2908 /* Don't look at what we have completed */
2909 continue;
2910 }
2911 /* If we reach here its a allocated closed end request */
2912 if ((ent->start == offset) ||
2913 ((offset > ent->start) && (offset < ent->end))){
2914 /* Its within this request?? */
2915 fnd = 1;
2916 }
2917 if (fnd) {
2918 /*
2919 * It is at or past the end, its complete.
2920 */
2921 ent->flags |= TCP_TRK_TRACK_FLG_SEQV;
2922 /*
2923 * When an entry completes we can take (snd_una + sb_cc) and know where
2924 * the end of the range really is. Note that this works since two
2925 * requests must be sequential and sendfile now is complete for *this* request.
2926 * we must use sb_ccc since the data may still be in-flight in TLS.
2927 *
2928 * We always cautiously move the end_seq only if our calculations
2929 * show it happened (just in case sf has the call to here at the wrong
2930 * place). When we go COMP we will stop coming here and hopefully be
2931 * left with the correct end_seq.
2932 */
2933 if (SEQ_GT((tp->snd_una + so->so_snd.sb_ccc), ent->end_seq))
2934 ent->end_seq = tp->snd_una + so->so_snd.sb_ccc;
2935 if ((offset + nbytes) >= ent->end) {
2936 ent->flags |= TCP_TRK_TRACK_FLG_COMP;
2937 tcp_req_log_req_info(tp, ent, i, TCP_TRK_REQ_LOG_COMPLETE, offset, nbytes);
2938 } else {
2939 tcp_req_log_req_info(tp, ent, i, TCP_TRK_REQ_LOG_MOREYET, offset, nbytes);
2940 }
2941 /* We assume that sendfile never sends overlapping requests */
2942 goto done;
2943 }
2944 }
2945 skip_closed_req:
2946 if (!fnd) {
2947 /* Ok now lets look for open requests */
2948 for(i = 0; i < MAX_TCP_TRK_REQ; i++) {
2949 ent = &tp->t_tcpreq_info[i];
2950 if (ent->flags == TCP_TRK_TRACK_FLG_EMPTY) {
2951 /* Not used */
2952 continue;
2953 }
2954 if ((ent->flags & TCP_TRK_TRACK_FLG_OPEN) == 0)
2955 continue;
2956 /* If we reach here its an allocated open request */
2957 if (ent->start == offset) {
2958 /* It begins this request */
2959 ent->start_seq = tp->snd_una +
2960 tptosocket(tp)->so_snd.sb_ccc;
2961 ent->flags |= TCP_TRK_TRACK_FLG_SEQV;
2962 break;
2963 } else if (offset > ent->start) {
2964 ent->flags |= TCP_TRK_TRACK_FLG_SEQV;
2965 break;
2966 }
2967 }
2968 }
2969 #endif
2970 done:
2971 INP_WUNLOCK(inp);
2972 }
2973