xref: /xnu-11417.101.15/bsd/netinet/tcp_log.c (revision e3723e1f17661b24996789d8afc084c0c3303b26)
1 /*
2  * Copyright (c) 2018-2024 Apple Inc. All rights reserved.
3  *
4  * @APPLE_OSREFERENCE_LICENSE_HEADER_START@
5  *
6  * This file contains Original Code and/or Modifications of Original Code
7  * as defined in and that are subject to the Apple Public Source License
8  * Version 2.0 (the 'License'). You may not use this file except in
9  * compliance with the License. The rights granted to you under the License
10  * may not be used to create, or enable the creation or redistribution of,
11  * unlawful or unlicensed copies of an Apple operating system, or to
12  * circumvent, violate, or enable the circumvention or violation of, any
13  * terms of an Apple operating system software license agreement.
14  *
15  * Please obtain a copy of the License at
16  * http://www.opensource.apple.com/apsl/ and read it before using this file.
17  *
18  * The Original Code and all software distributed under the License are
19  * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER
20  * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,
21  * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,
22  * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT.
23  * Please see the License for the specific language governing rights and
24  * limitations under the License.
25  *
26  * @APPLE_OSREFERENCE_LICENSE_HEADER_END@
27  */
28 
29 #include <sys/param.h>
30 #include <sys/protosw.h>
31 #include <sys/systm.h>
32 #include <sys/sysctl.h>
33 
34 #include <kern/bits.h>
35 
36 #include <netinet/ip.h>
37 #include <netinet/ip6.h>
38 #include <netinet/inp_log.h>
39 
40 #define TCPSTATES
41 #include <netinet/tcp_fsm.h>
42 
43 #include <netinet/tcp_log.h>
44 
45 SYSCTL_NODE(_net_inet_tcp, OID_AUTO, log, CTLFLAG_RW | CTLFLAG_LOCKED, 0,
46     "TCP logs");
47 
48 #if (DEVELOPMENT || DEBUG)
49 #define TCP_LOG_ENABLE_DEFAULT \
50     (TLEF_CONNECTION | TLEF_DST_LOCAL | TLEF_DST_GW | \
51     TLEF_DROP_NECP | TLEF_DROP_PCB | TLEF_DROP_PKT | \
52     TLEF_SYN_RXMT | TLEF_LOG)
53 #else /* (DEVELOPMENT || DEBUG) */
54 #define TCP_LOG_ENABLE_DEFAULT 0
55 #endif /* (DEVELOPMENT || DEBUG) */
56 
57 uint32_t tcp_log_enable_flags = TCP_LOG_ENABLE_DEFAULT;
58 SYSCTL_UINT(_net_inet_tcp_log, OID_AUTO, enable,
59     CTLFLAG_RW | CTLFLAG_LOCKED, &tcp_log_enable_flags, 0, "");
60 
61 /*
62  * The following is a help to describe the values of the flags
63  */
64 #define X(name, value, description, ...) #description ":" #value " "
65 SYSCTL_STRING(_net_inet_tcp_log, OID_AUTO, enable_usage, CTLFLAG_RD | CTLFLAG_LOCKED,
66     TCP_ENABLE_FLAG_LIST, 0, "");
67 #undef X
68 
69 static int sysctl_tcp_log_port SYSCTL_HANDLER_ARGS;
70 
71 uint16_t tcp_log_port = 0;
72 SYSCTL_PROC(_net_inet_tcp_log, OID_AUTO, rtt_port,
73     CTLFLAG_RW | CTLFLAG_LOCKED | CTLTYPE_INT, &tcp_log_port, 0,
74     sysctl_tcp_log_port, "UI", "");
75 
76 /*
77  * Bitmap for tcp_log_thflags_if_family when TLEF_THF_XXX is enabled:
78  *  0: off
79  *  other: only for interfaces with the corresponding interface family in the bitmap
80  */
81 #if (DEVELOPMENT || DEBUG)
82 #define TCP_LOG_THFLAGS_IF_FAMILY_DEFAULT (0xfffffffe & ~BIT(IFNET_FAMILY_LOOPBACK))
83 #else /* (DEVELOPMENT || DEBUG) */
84 #define TCP_LOG_THFLAGS_IF_FAMILY_DEFAULT 0
85 #endif /* (DEVELOPMENT || DEBUG) */
86 
87 static uint64_t tcp_log_thflags_if_family = TCP_LOG_THFLAGS_IF_FAMILY_DEFAULT;
88 SYSCTL_QUAD(_net_inet_tcp_log, OID_AUTO, thflags_if_family,
89     CTLFLAG_RW | CTLFLAG_LOCKED, &tcp_log_thflags_if_family, "");
90 
91 #define TCP_LOG_RATE_LIMIT 1000
92 static unsigned int tcp_log_rate_limit = TCP_LOG_RATE_LIMIT;
93 SYSCTL_UINT(_net_inet_tcp_log, OID_AUTO, rate_limit,
94     CTLFLAG_RW | CTLFLAG_LOCKED, &tcp_log_rate_limit, 0, "");
95 
96 /* 1 minute by default */
97 #define TCP_LOG_RATE_DURATION 60
98 static unsigned int tcp_log_rate_duration = TCP_LOG_RATE_DURATION;
99 SYSCTL_UINT(_net_inet_tcp_log, OID_AUTO, rate_duration,
100     CTLFLAG_RW | CTLFLAG_LOCKED, &tcp_log_rate_duration, 0, "");
101 
102 static unsigned long tcp_log_rate_max = 0;
103 SYSCTL_ULONG(_net_inet_tcp_log, OID_AUTO, rate_max,
104     CTLFLAG_RD | CTLFLAG_LOCKED, &tcp_log_rate_max, "");
105 
106 static unsigned long tcp_log_rate_exceeded_total = 0;
107 SYSCTL_ULONG(_net_inet_tcp_log, OID_AUTO, rate_exceeded_total,
108     CTLFLAG_RD | CTLFLAG_LOCKED, &tcp_log_rate_exceeded_total, "");
109 
110 static unsigned long tcp_log_rate_current = 0;
111 SYSCTL_ULONG(_net_inet_tcp_log, OID_AUTO, rate_current,
112     CTLFLAG_RD | CTLFLAG_LOCKED, &tcp_log_rate_current, "");
113 
114 static bool tcp_log_rate_exceeded_logged = false;
115 
116 static uint64_t tcp_log_current_period = 0;
117 
118 #define ADDRESS_STR_LEN (MAX_IPv6_STR_LEN + 6)
119 
120 #define TCP_LOG_COMMON_FMT \
121 	    "[%s:%u<->%s:%u] " \
122 	    "interface: %s " \
123 	    "(skipped: %lu)\n"
124 
125 #define TCP_LOG_COMMON_ARGS \
126 	laddr_buf, ntohs(local_port), faddr_buf, ntohs(foreign_port), \
127 	    ifp != NULL ? if_name(ifp) : "", \
128 	    tcp_log_rate_exceeded_total
129 
130 #define TCP_LOG_COMMON_PCB_FMT \
131 	TCP_LOG_COMMON_FMT \
132 	"so_gencnt: %llu " \
133 	"t_state: %s " \
134 	"process: %s:%u "
135 
136 #define TCP_LOG_COMMON_PCB_ARGS \
137 	TCP_LOG_COMMON_ARGS, \
138 	so != NULL ? so->so_gencnt : 0, \
139 	tcpstates[tp->t_state], \
140 	inp->inp_last_proc_name, so->last_pid
141 
142 /*
143  * Returns true when above the rate limit
144  */
145 static bool
tcp_log_is_rate_limited(void)146 tcp_log_is_rate_limited(void)
147 {
148 	uint64_t current_net_period = net_uptime();
149 
150 	/* When set to zero it means to reset to default */
151 	if (tcp_log_rate_duration == 0) {
152 		tcp_log_rate_duration = TCP_LOG_RATE_DURATION;
153 	}
154 	if (tcp_log_rate_limit == 0) {
155 		tcp_log_rate_duration = TCP_LOG_RATE_LIMIT;
156 	}
157 
158 	if (current_net_period > tcp_log_current_period + tcp_log_rate_duration) {
159 		if (tcp_log_rate_current > tcp_log_rate_max) {
160 			tcp_log_rate_max = tcp_log_rate_current;
161 		}
162 		tcp_log_current_period = current_net_period;
163 		tcp_log_rate_current = 0;
164 		tcp_log_rate_exceeded_logged = false;
165 	}
166 
167 	tcp_log_rate_current += 1;
168 
169 	if (tcp_log_rate_current > (unsigned long) tcp_log_rate_limit) {
170 		tcp_log_rate_exceeded_total += 1;
171 		return true;
172 	}
173 
174 	return false;
175 }
176 
177 static void
tcp_log_inp_addresses(struct inpcb * inp,char * __sized_by (lbuflen)lbuf,socklen_t lbuflen,char * __sized_by (fbuflen)fbuf,socklen_t fbuflen)178 tcp_log_inp_addresses(struct inpcb *inp, char *__sized_by(lbuflen) lbuf, socklen_t lbuflen,
179     char *__sized_by(fbuflen) fbuf, socklen_t fbuflen)
180 {
181 	/*
182 	 * Ugly but %{private} does not work in the kernel version of os_log()
183 	 */
184 	if (inp_log_privacy != 0) {
185 		if (inp->inp_vflag & INP_IPV6) {
186 			strlcpy(lbuf, "<IPv6-redacted>", lbuflen);
187 			strlcpy(fbuf, "<IPv6-redacted>", fbuflen);
188 		} else {
189 			strlcpy(lbuf, "<IPv4-redacted>", lbuflen);
190 			strlcpy(fbuf, "<IPv4-redacted>", fbuflen);
191 		}
192 	} else if (inp->inp_vflag & INP_IPV6) {
193 		struct in6_addr addr6;
194 
195 		if (IN6_IS_ADDR_LINKLOCAL(&inp->in6p_laddr)) {
196 			addr6 = inp->in6p_laddr;
197 			addr6.s6_addr16[1] = 0;
198 			inet_ntop(AF_INET6, (void *)&addr6, lbuf, lbuflen);
199 		} else {
200 			inet_ntop(AF_INET6, (void *)&inp->in6p_laddr, lbuf, lbuflen);
201 		}
202 
203 		if (IN6_IS_ADDR_LINKLOCAL(&inp->in6p_faddr)) {
204 			addr6 = inp->in6p_faddr;
205 			addr6.s6_addr16[1] = 0;
206 			inet_ntop(AF_INET6, (void *)&addr6, fbuf, fbuflen);
207 		} else {
208 			inet_ntop(AF_INET6, (void *)&inp->in6p_faddr, fbuf, fbuflen);
209 		}
210 	} else {
211 		inet_ntop(AF_INET, (void *)&inp->inp_laddr.s_addr, lbuf, lbuflen);
212 		inet_ntop(AF_INET, (void *)&inp->inp_faddr.s_addr, fbuf, fbuflen);
213 	}
214 }
215 
216 __attribute__((noinline))
217 void
tcp_log_rtt_info(const char * func_name,int line_no,struct tcpcb * tp)218 tcp_log_rtt_info(const char *func_name, int line_no, struct tcpcb *tp)
219 {
220 	struct inpcb *inp = tp->t_inpcb;
221 	struct socket *so = inp->inp_socket;
222 	struct ifnet *ifp;
223 	char laddr_buf[ADDRESS_STR_LEN];
224 	char faddr_buf[ADDRESS_STR_LEN];
225 	in_port_t local_port = inp->inp_lport;
226 	in_port_t foreign_port = inp->inp_fport;
227 
228 	/* Do not log too much */
229 	if (tcp_log_is_rate_limited()) {
230 		return;
231 	}
232 
233 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
234 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
235 
236 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
237 
238 	os_log(OS_LOG_DEFAULT,
239 	    "tcp_rtt_info (%s:%d) "
240 	    TCP_LOG_COMMON_PCB_FMT
241 	    "base_rtt: %u ms rttcur: %u ms srtt: %u ms rttvar: %u ms rttmin: %u ms rxtcur: %u rxtshift: %u",
242 	    func_name, line_no,
243 	    TCP_LOG_COMMON_PCB_ARGS, get_base_rtt(tp),
244 	    tp->t_rttcur, tp->t_srtt >> TCP_RTT_SHIFT,
245 	    tp->t_rttvar >> TCP_RTTVAR_SHIFT,
246 	    tp->t_rttmin, tp->t_rxtcur, tp->t_rxtshift);
247 }
248 
249 __attribute__((noinline))
250 void
tcp_log_rt_rtt(const char * func_name,int line_no,struct tcpcb * tp,struct rtentry * rt)251 tcp_log_rt_rtt(const char *func_name, int line_no, struct tcpcb *tp,
252     struct rtentry *rt)
253 {
254 	struct inpcb *inp = tp->t_inpcb;
255 	struct socket *so = inp->inp_socket;
256 	struct ifnet *ifp;
257 	char laddr_buf[ADDRESS_STR_LEN];
258 	char faddr_buf[ADDRESS_STR_LEN];
259 	in_port_t local_port = inp->inp_lport;
260 	in_port_t foreign_port = inp->inp_fport;
261 
262 	/* Do not log too much */
263 	if (tcp_log_is_rate_limited()) {
264 		return;
265 	}
266 
267 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
268 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
269 
270 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
271 
272 	/*
273 	 * Log RTT values in milliseconds
274 	 */
275 	os_log(OS_LOG_DEFAULT,
276 	    "tcp_rt_rtt (%s:%d) "
277 	    TCP_LOG_COMMON_PCB_FMT
278 	    "rt_rmx: RTV_RTT: %d ms rtt: %u ms rttvar: %u ms",
279 	    func_name, line_no,
280 	    TCP_LOG_COMMON_PCB_ARGS,
281 	    (rt->rt_rmx.rmx_locks & RTV_RTT),
282 	    rt->rt_rmx.rmx_rtt / (RTM_RTTUNIT / TCP_RETRANSHZ),
283 	    rt->rt_rmx.rmx_rttvar / (RTM_RTTUNIT / TCP_RETRANSHZ));
284 }
285 
286 __attribute__((noinline))
287 void
tcp_log_rtt_change(const char * func_name,int line_no,struct tcpcb * tp,int old_srtt,int old_rttvar)288 tcp_log_rtt_change(const char *func_name, int line_no, struct tcpcb *tp,
289     int old_srtt, int old_rttvar)
290 {
291 	int srtt_diff;
292 	int rttvar_diff;
293 
294 	srtt_diff = ABS(tp->t_srtt  - old_srtt) >> TCP_RTT_SHIFT;
295 	rttvar_diff =
296 	    ABS((tp->t_rttvar - old_rttvar) >> TCP_RTTVAR_SHIFT);
297 	if (srtt_diff >= 1000 || rttvar_diff >= 500) {
298 		struct inpcb *inp = tp->t_inpcb;
299 		struct socket *so = inp->inp_socket;
300 		struct ifnet *ifp;
301 		char laddr_buf[ADDRESS_STR_LEN];
302 		char faddr_buf[ADDRESS_STR_LEN];
303 		in_port_t local_port = inp->inp_lport;
304 		in_port_t foreign_port = inp->inp_fport;
305 
306 		/* Do not log too much */
307 		if (tcp_log_is_rate_limited()) {
308 			return;
309 		}
310 
311 		ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
312 		    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
313 
314 		tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
315 
316 		os_log(OS_LOG_DEFAULT,
317 		    "tcp_rtt_change (%s:%d) "
318 		    TCP_LOG_COMMON_PCB_FMT
319 		    "srtt: %u ms old_rtt: %u ms "
320 		    "rttvar: %u old_rttvar: %u ms ",
321 		    func_name, line_no,
322 		    TCP_LOG_COMMON_PCB_ARGS,
323 		    tp->t_srtt >> TCP_RTT_SHIFT,
324 		    old_srtt >> TCP_RTT_SHIFT,
325 		    tp->t_rttvar >> TCP_RTTVAR_SHIFT,
326 		    old_rttvar >> TCP_RTTVAR_SHIFT);
327 	}
328 }
329 
330 __attribute__((noinline))
331 void
tcp_log_keepalive(const char * func_name,int line_no,struct tcpcb * tp,int32_t idle_time)332 tcp_log_keepalive(const char *func_name, int line_no, struct tcpcb *tp,
333     int32_t idle_time)
334 {
335 	struct inpcb *inp = tp->t_inpcb;
336 	struct socket *so = inp->inp_socket;
337 	struct ifnet *ifp;
338 	char laddr_buf[ADDRESS_STR_LEN];
339 	char faddr_buf[ADDRESS_STR_LEN];
340 	in_port_t local_port = inp->inp_lport;
341 	in_port_t foreign_port = inp->inp_fport;
342 
343 	/* Do not log too much */
344 	if (tcp_log_is_rate_limited()) {
345 		return;
346 	}
347 
348 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
349 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
350 
351 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
352 
353 	os_log(OS_LOG_DEFAULT,
354 	    "tcp_keepalive (%s:%d) "
355 	    TCP_LOG_COMMON_PCB_FMT
356 	    "snd_una: %u snd_max: %u "
357 	    "SO_KA: %d RSTALL: %d TFOPRB: %d idle_time: %u "
358 	    "KIDLE: %d KINTV: %d KCNT: %d",
359 	    func_name, line_no,
360 	    TCP_LOG_COMMON_PCB_ARGS,
361 	    tp->snd_una, tp->snd_max,
362 	    tp->t_inpcb->inp_socket->so_options & SO_KEEPALIVE,
363 	    tp->t_flagsext & TF_DETECT_READSTALL,
364 	    tp->t_tfo_probe_state == TFO_PROBE_PROBING,
365 	    idle_time,
366 	    TCP_CONN_KEEPIDLE(tp), TCP_CONN_KEEPINTVL(tp),
367 	    TCP_CONN_KEEPCNT(tp));
368 }
369 
370 #define P_MS(ms, shift) ((ms) >> (shift)), (((ms) * 1000) >> (shift)) % 1000
371 
372 __attribute__((noinline))
373 void
tcp_log_connection(struct tcpcb * tp,const char * event,int error)374 tcp_log_connection(struct tcpcb *tp, const char *event, int error)
375 {
376 	struct inpcb *inp;
377 	struct socket *so;
378 	struct ifnet *ifp;
379 	char laddr_buf[ADDRESS_STR_LEN];
380 	char faddr_buf[ADDRESS_STR_LEN];
381 	in_port_t local_port;
382 	in_port_t foreign_port;
383 
384 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL || event == NULL) {
385 		return;
386 	}
387 
388 	/* Do not log too much */
389 	if (tcp_log_is_rate_limited()) {
390 		return;
391 	}
392 	inp = tp->t_inpcb;
393 	so = inp->inp_socket;
394 
395 	inp->inp_flags2 |= INP2_LOGGING_ENABLED;
396 
397 	local_port = inp->inp_lport;
398 	foreign_port = inp->inp_fport;
399 
400 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
401 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
402 
403 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
404 
405 #define TCP_LOG_CONNECT_FMT \
406 	    "tcp %s: " \
407 	    TCP_LOG_COMMON_PCB_FMT \
408 	    "SYN in/out: %u/%u " \
409 	    "bytes in/out: %llu/%llu " \
410 	    "pkts in/out: %llu/%llu " \
411 	    "rtt: %u.%u ms " \
412 	    "rttvar: %u.%u ms " \
413 	    "base_rtt: %u ms " \
414 	    "error: %d " \
415 	    "so_error: %d " \
416 	    "svc/tc: %u " \
417 	    "flow: 0x%x"
418 
419 #define TCP_LOG_CONNECT_ARGS \
420 	    event, \
421 	    TCP_LOG_COMMON_PCB_ARGS, \
422 	    tp->t_syn_rcvd, tp->t_syn_sent, \
423 	    inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
424 	    inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
425 	    P_MS(tp->t_srtt, TCP_RTT_SHIFT), \
426 	    P_MS(tp->t_rttvar, TCP_RTTVAR_SHIFT), \
427 	    get_base_rtt(tp), \
428 	    error, \
429 	    so->so_error, \
430 	    (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \
431 	    inp->inp_flowhash
432 
433 	if (so->so_head == NULL) {
434 		os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECT_FMT,
435 		    TCP_LOG_CONNECT_ARGS);
436 	} else {
437 #define TCP_LOG_CONN_Q_FMT \
438 	"so_qlimit: %d "\
439 	"so_qlen: %d "\
440 	"so_incqlen: %d "
441 
442 #define TCP_LOG_CONN_Q_ARGS \
443 	so->so_head->so_qlimit, \
444 	so->so_head->so_qlen, \
445 	so->so_head->so_incqlen
446 
447 		os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECT_FMT "\n" TCP_LOG_CONN_Q_FMT,
448 		    TCP_LOG_CONNECT_ARGS, TCP_LOG_CONN_Q_ARGS);
449 #undef TCP_LOG_CONN_Q_FMT
450 #undef TCP_LOG_CONN_Q_ARGS
451 	}
452 #undef TCP_LOG_CONNECT_FMT
453 #undef TCP_LOG_CONNECT_ARGS
454 }
455 
456 __attribute__((noinline))
457 void
tcp_log_listen(struct tcpcb * tp,int error)458 tcp_log_listen(struct tcpcb *tp, int error)
459 {
460 	struct inpcb *inp = tp->t_inpcb;
461 	struct socket *so = inp->inp_socket;
462 	struct ifnet *ifp;
463 	char laddr_buf[ADDRESS_STR_LEN];
464 	char faddr_buf[ADDRESS_STR_LEN];
465 	in_port_t local_port;
466 	in_port_t foreign_port;
467 
468 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
469 		return;
470 	}
471 
472 	/* Do not log too much */
473 	if (tcp_log_is_rate_limited()) {
474 		return;
475 	}
476 	inp = tp->t_inpcb;
477 	so = inp->inp_socket;
478 
479 	inp->inp_flags2 |= INP2_LOGGING_ENABLED;
480 
481 	local_port = inp->inp_lport;
482 	foreign_port = inp->inp_fport;
483 
484 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
485 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
486 
487 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
488 
489 #define TCP_LOG_LISTEN_FMT \
490 	    "tcp listen: " \
491 	    TCP_LOG_COMMON_PCB_FMT \
492 	    "so_qlimit: %d "\
493 	    "error: %d " \
494 	    "so_error: %d " \
495 	    "svc/tc: %u"
496 
497 #define TCP_LOG_LISTEN_ARGS \
498 	    TCP_LOG_COMMON_PCB_ARGS, \
499 	    so->so_qlimit, \
500 	    error, \
501 	    so->so_error, \
502 	    (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class
503 
504 	os_log(OS_LOG_DEFAULT, TCP_LOG_LISTEN_FMT,
505 	    TCP_LOG_LISTEN_ARGS);
506 #undef TCP_LOG_LISTEN_FMT
507 #undef TCP_LOG_LISTEN_ARGS
508 }
509 
510 static const char *
tcp_connection_client_accurate_ecn_state_to_string(tcp_connection_client_accurate_ecn_state_t state)511 tcp_connection_client_accurate_ecn_state_to_string(tcp_connection_client_accurate_ecn_state_t state)
512 {
513 	switch (state) {
514 #define ECN_STATE_TO_STRING(_s, _str) \
515 	case tcp_connection_client_accurate_ecn_##_s: { \
516 	        return _str; \
517 	}
518 		ECN_STATE_TO_STRING(invalid, "Invalid")
519 		ECN_STATE_TO_STRING(feature_disabled, "Disabled")
520 		ECN_STATE_TO_STRING(feature_enabled, "Enabled")
521 		ECN_STATE_TO_STRING(negotiation_blackholed, "Blackholed")
522 		ECN_STATE_TO_STRING(ace_bleaching_detected, "ACE bleaching")
523 		ECN_STATE_TO_STRING(negotiation_success, "Capable")
524 		ECN_STATE_TO_STRING(negotiation_success_ect_mangling_detected, "ECT mangling")
525 		ECN_STATE_TO_STRING(negotiation_success_ect_bleaching_detected, "ECT bleaching")
526 #undef ECN_STATE_TO_STRING
527 	case tcp_connection_client_classic_ecn_available:
528 		return "Classic ECN";
529 	case tcp_connection_client_ecn_not_available:
530 		return "Unavailable";
531 	}
532 	return "Unknown";
533 }
534 
535 static const char *
tcp_connection_server_accurate_ecn_state_to_string(tcp_connection_server_accurate_ecn_state_t state)536 tcp_connection_server_accurate_ecn_state_to_string(tcp_connection_server_accurate_ecn_state_t state)
537 {
538 	switch (state) {
539 #define ECN_STATE_TO_STRING(_s, _str) \
540 	case tcp_connection_server_accurate_ecn_##_s: { \
541 	        return _str; \
542 	}
543 		ECN_STATE_TO_STRING(invalid, "Invalid")
544 		ECN_STATE_TO_STRING(feature_disabled, "Disabled")
545 		ECN_STATE_TO_STRING(feature_enabled, "Enabled")
546 		ECN_STATE_TO_STRING(requested, "Requested")
547 		ECN_STATE_TO_STRING(negotiation_blackholed, "Blackholed")
548 		ECN_STATE_TO_STRING(ace_bleaching_detected, "ACE bleaching")
549 		ECN_STATE_TO_STRING(negotiation_success, "Capable")
550 		ECN_STATE_TO_STRING(negotiation_success_ect_mangling_detected, "ECT mangling")
551 		ECN_STATE_TO_STRING(negotiation_success_ect_bleaching_detected, "ECT bleaching")
552 #undef ECN_STATE_TO_STRING
553 	case tcp_connection_server_no_ecn_requested:
554 		return "Not requested";
555 	case tcp_connection_server_classic_ecn_requested:
556 		return "Classic ECN requested";
557 	}
558 	return "Unknown";
559 }
560 
561 __attribute__((noinline))
562 void
tcp_log_connection_summary(const char * func_name,int line_no,struct tcpcb * tp)563 tcp_log_connection_summary(const char *func_name, int line_no, struct tcpcb *tp)
564 {
565 	struct inpcb *inp;
566 	struct socket *so;
567 	struct ifnet *ifp;
568 	uint32_t conntime = 0;
569 	uint32_t duration = 0;
570 	char laddr_buf[ADDRESS_STR_LEN];
571 	char faddr_buf[ADDRESS_STR_LEN];
572 	in_port_t local_port;
573 	in_port_t foreign_port;
574 
575 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
576 		return;
577 	}
578 
579 	/* Do not log too much */
580 	if (tcp_log_is_rate_limited()) {
581 		return;
582 	}
583 	inp = tp->t_inpcb;
584 	so = inp->inp_socket;
585 
586 	local_port = inp->inp_lport;
587 	foreign_port = inp->inp_fport;
588 
589 	/* Make sure the summary is logged once */
590 	if (inp->inp_flags2 & INP2_LOGGED_SUMMARY) {
591 		return;
592 	}
593 	inp->inp_flags2 |= INP2_LOGGED_SUMMARY;
594 	inp->inp_flags2 &= ~INP2_LOGGING_ENABLED;
595 
596 	/*
597 	 * t_connect_time is the time when the connection started on
598 	 * the first SYN.
599 	 *
600 	 * t_starttime is when the three way handshake was completed.
601 	 */
602 	if (tp->t_connect_time > 0) {
603 		duration = tcp_now - tp->t_connect_time;
604 
605 		if (tp->t_starttime > 0) {
606 			conntime = tp->t_starttime - tp->t_connect_time;
607 		}
608 	}
609 
610 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
611 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
612 
613 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
614 
615 	/*
616 	 * Need to use 2 log messages because the size of the summary
617 	 */
618 
619 #define TCP_LOG_CONNECTION_SUMMARY_FMT \
620 	    "tcp_connection_summary (%s:%d)" \
621 	    TCP_LOG_COMMON_PCB_FMT \
622 	    "Duration: %u.%03u sec " \
623 	    "Conn_Time: %u.%03u sec " \
624 	    "bytes in/out: %llu/%llu " \
625 	    "pkts in/out: %llu/%llu " \
626 	    "pkt rxmit: %u " \
627 	    "ooo pkts: %u dup bytes in: %u ACKs delayed: %u delayed ACKs sent: %u\n" \
628 	    "rtt: %u.%03u ms "  \
629 	    "rttvar: %u.%03u ms " \
630 	    "base rtt: %u ms " \
631 	    "so_error: %d " \
632 	    "svc/tc: %u " \
633 	    "flow: 0x%x"
634 
635 #define TCP_LOG_CONNECTION_SUMMARY_ARGS \
636 	    func_name, line_no, \
637 	    TCP_LOG_COMMON_PCB_ARGS,  \
638 	    duration / TCP_RETRANSHZ, duration % TCP_RETRANSHZ, \
639 	    conntime / TCP_RETRANSHZ, conntime % TCP_RETRANSHZ,  \
640 	    inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
641 	    inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
642 	    tp->t_stat.rxmitpkts, \
643 	    tp->t_rcvoopack, tp->t_stat.rxduplicatebytes, tp->t_stat.acks_delayed, tp->t_stat.delayed_acks_sent, \
644 	    P_MS(tp->t_srtt, TCP_RTT_SHIFT), \
645 	    P_MS(tp->t_rttvar, TCP_RTTVAR_SHIFT), \
646 	    get_base_rtt(tp), \
647 	    so->so_error, \
648 	    (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \
649 	    inp->inp_flowhash
650 
651 	os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECTION_SUMMARY_FMT,
652 	    TCP_LOG_CONNECTION_SUMMARY_ARGS);
653 #undef TCP_LOG_CONNECTION_SUMMARY_FMT
654 #undef TCP_LOG_CONNECTION_SUMMARY_ARGS
655 
656 #define TCP_LOG_CONNECTION_SUMMARY_FMT \
657 	    "tcp_connection_summary " \
658 	    TCP_LOG_COMMON_PCB_FMT \
659 	    "flowctl: %lluus (%llux) " \
660 	    "SYN in/out: %u/%u " \
661 	    "FIN in/out: %u/%u " \
662 	    "RST in/out: %u/%u " \
663 	    "AccECN (client/server): %s/%s\n" \
664 
665 #define TCP_LOG_CONNECTION_SUMMARY_ARGS \
666 	    TCP_LOG_COMMON_PCB_ARGS, \
667 	    inp->inp_fadv_total_time, \
668 	    inp->inp_fadv_cnt, \
669 	    tp->t_syn_rcvd, tp->t_syn_sent, \
670 	    tp->t_fin_rcvd, tp->t_fin_sent, \
671 	    tp->t_rst_rcvd, tp->t_rst_sent, \
672 	    tcp_connection_client_accurate_ecn_state_to_string(tp->t_client_accecn_state), \
673 	    tcp_connection_server_accurate_ecn_state_to_string(tp->t_server_accecn_state)
674 
675 	os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECTION_SUMMARY_FMT,
676 	    TCP_LOG_CONNECTION_SUMMARY_ARGS);
677 #undef TCP_LOG_CONNECTION_SUMMARY_FMT
678 #undef TCP_LOG_CONNECTION_SUMMARY_ARGS
679 }
680 
681 __attribute__((noinline))
682 static bool
tcp_log_pkt_addresses(void * hdr,struct tcphdr * th,bool outgoing,char * __sized_by (lbuflen)lbuf,socklen_t lbuflen,char * __sized_by (fbuflen)fbuf,socklen_t fbuflen)683 tcp_log_pkt_addresses(void *hdr, struct tcphdr *th, bool outgoing,
684     char *__sized_by(lbuflen) lbuf, socklen_t lbuflen,
685     char *__sized_by(fbuflen) fbuf, socklen_t fbuflen)
686 {
687 	bool isipv6;
688 	uint8_t thflags;
689 
690 	isipv6 = (((struct ip *)hdr)->ip_v == 6);
691 	thflags = th->th_flags;
692 
693 	if (isipv6) {
694 		struct ip6_hdr *ip6 = (struct ip6_hdr *)hdr;
695 		struct in6_addr src_addr6 = ip6->ip6_src;
696 		struct in6_addr dst_addr6 = ip6->ip6_dst;
697 
698 #pragma clang diagnostic push
699 #pragma clang diagnostic ignored "-Waddress-of-packed-member"
700 		if (memcmp(&src_addr6, &in6addr_loopback, sizeof(struct in6_addr)) == 0 ||
701 		    memcmp(&dst_addr6, &in6addr_loopback, sizeof(struct in6_addr)) == 0) {
702 			if (!(tcp_log_enable_flags & TLEF_DST_LOOPBACK)) {
703 				return false;
704 			}
705 		}
706 #pragma clang diagnostic pop
707 
708 		if (IN6_IS_ADDR_LINKLOCAL(&src_addr6)) {
709 			src_addr6.s6_addr16[1] = 0;
710 		}
711 		if (IN6_IS_ADDR_LINKLOCAL(&dst_addr6)) {
712 			dst_addr6.s6_addr16[1] = 0;
713 		}
714 
715 		if (inp_log_privacy != 0) {
716 			strlcpy(lbuf, "<IPv6-redacted>", lbuflen);
717 			strlcpy(fbuf, "<IPv6-redacted>", fbuflen);
718 		} else if (outgoing) {
719 			inet_ntop(AF_INET6, &src_addr6, lbuf, lbuflen);
720 			inet_ntop(AF_INET6, &dst_addr6, fbuf, fbuflen);
721 		} else {
722 			inet_ntop(AF_INET6, &dst_addr6, lbuf, lbuflen);
723 			inet_ntop(AF_INET6, &src_addr6, fbuf, fbuflen);
724 		}
725 	} else {
726 		struct ip *ip = (struct ip *)hdr;
727 
728 		if (ntohl(ip->ip_src.s_addr) == INADDR_LOOPBACK ||
729 		    ntohl(ip->ip_dst.s_addr) == INADDR_LOOPBACK) {
730 			if (!(tcp_log_enable_flags & TLEF_DST_LOOPBACK)) {
731 				return false;
732 			}
733 		}
734 
735 		if (inp_log_privacy != 0) {
736 			strlcpy(lbuf, "<IPv4-redacted>", lbuflen);
737 			strlcpy(fbuf, "<IPv4-redacted>", fbuflen);
738 		} else if (outgoing) {
739 			inet_ntop(AF_INET, (void *)&ip->ip_src.s_addr, lbuf, lbuflen);
740 			inet_ntop(AF_INET, (void *)&ip->ip_dst.s_addr, fbuf, fbuflen);
741 		} else {
742 			inet_ntop(AF_INET, (void *)&ip->ip_dst.s_addr, lbuf, lbuflen);
743 			inet_ntop(AF_INET, (void *)&ip->ip_src.s_addr, fbuf, fbuflen);
744 		}
745 	}
746 	return true;
747 }
748 
749 /*
750  * Note: currently only used in the input path
751  */
752 __attribute__((noinline))
753 void
tcp_log_drop_pcb(void * hdr,struct tcphdr * th,struct tcpcb * tp,bool outgoing,const char * reason)754 tcp_log_drop_pcb(void *hdr, struct tcphdr *th, struct tcpcb *tp, bool outgoing, const char *reason)
755 {
756 	struct inpcb *inp;
757 	struct socket *so;
758 	struct ifnet *ifp;
759 	char laddr_buf[ADDRESS_STR_LEN];
760 	char faddr_buf[ADDRESS_STR_LEN];
761 	in_port_t local_port;
762 	in_port_t foreign_port;
763 	const char *direction = "";
764 
765 	if (tp == NULL) {
766 		return;
767 	}
768 	inp = tp->t_inpcb;
769 	if (inp == NULL) {
770 		return;
771 	}
772 	so = inp->inp_socket;
773 	if (so == NULL) {
774 		return;
775 	}
776 
777 	/* Do not log common drops after the connection termination is logged */
778 	if ((inp->inp_flags2 & INP2_LOGGED_SUMMARY) && ((so->so_state & SS_NOFDREF) ||
779 	    (so->so_flags & SOF_DEFUNCT) || (so->so_state & SS_CANTRCVMORE))) {
780 		return;
781 	}
782 
783 	/* Do not log too much */
784 	if (tcp_log_is_rate_limited()) {
785 		return;
786 	}
787 
788 	/* Use the packet addresses when in the data path */
789 	if (hdr != NULL && th != NULL) {
790 		if (outgoing) {
791 			local_port = th->th_sport;
792 			foreign_port = th->th_dport;
793 			direction = "outgoing ";
794 		} else {
795 			local_port = th->th_dport;
796 			foreign_port = th->th_sport;
797 			direction = "incoming ";
798 		}
799 		(void) tcp_log_pkt_addresses(hdr, th, outgoing, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
800 	} else {
801 		local_port = inp->inp_lport;
802 		foreign_port = inp->inp_fport;
803 		tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
804 	}
805 
806 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
807 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
808 
809 #define TCP_LOG_DROP_PCB_FMT \
810 	    "tcp drop %s" \
811 	    TCP_LOG_COMMON_PCB_FMT \
812 	    "t_state: %s " \
813 	    "so_error: %d " \
814 	    "reason: %s"
815 
816 #define TCP_LOG_DROP_PCB_ARGS \
817 	    direction, \
818 	    TCP_LOG_COMMON_PCB_ARGS, \
819 	    tcpstates[tp->t_state], \
820 	    so->so_error, \
821 	    reason
822 
823 	os_log(OS_LOG_DEFAULT, TCP_LOG_DROP_PCB_FMT,
824 	    TCP_LOG_DROP_PCB_ARGS);
825 #undef TCP_LOG_DROP_PCB_FMT
826 #undef TCP_LOG_DROP_PCB_ARGS
827 }
828 
829 #define TCP_LOG_TH_FLAGS_COMMON_FMT \
830 	"tcp control %s " \
831 	"%s" \
832 	"%s" \
833 	"%s" \
834 	"%s"
835 
836 #define TCP_LOG_TH_FLAGS_COMMON_ARGS \
837 	outgoing ? "outgoing" : "incoming", \
838 	thflags & TH_SYN ? "SYN " : "", \
839 	thflags & TH_FIN ? "FIN " : "", \
840 	thflags & TH_RST ? "RST " : "", \
841 	thflags & TH_ACK ? "ACK " : ""
842 
843 static bool
should_log_th_flags(uint8_t thflags,struct tcpcb * tp,bool outgoing,struct ifnet * ifp)844 should_log_th_flags(uint8_t thflags, struct tcpcb *tp, bool outgoing, struct ifnet *ifp)
845 {
846 	/*
847 	 * Check logging is enabled for interface for TCP control packets
848 	 *
849 	 * Note: the type of tcp_log_thflags_if_family is uint64_t but we
850 	 * access its value as bit string so we have to pay extra care to avoid
851 	 * out of bound access
852 	 */
853 	if (ifp != NULL && (ifp->if_family >= (sizeof(tcp_log_thflags_if_family) << 3) ||
854 	    !bitstr_test((bitstr_t *)&tcp_log_thflags_if_family, ifp->if_family))) {
855 		return false;
856 	}
857 	/*
858 	 * Log when seeing 3 SYN retransmissions of more on a TCP PCB
859 	 */
860 	if (tp != NULL &&
861 	    ((thflags & TH_SYN) && (tcp_log_enable_flags & TLEF_SYN_RXMT) &&
862 	    ((outgoing && tp->t_syn_sent > 3) || (!outgoing && tp->t_syn_rcvd > 3)))) {
863 		return true;
864 	}
865 	/*
866 	 * Log control packet when enabled
867 	 */
868 	if ((((thflags & TH_SYN) && (tcp_log_enable_flags & TLEF_THF_SYN)) ||
869 	    ((thflags & TH_FIN) && (tcp_log_enable_flags & TLEF_THF_FIN)) ||
870 	    ((thflags & TH_RST) && (tcp_log_enable_flags & TLEF_THF_RST)))) {
871 		return true;
872 	}
873 	return false;
874 }
875 
876 __attribute__((noinline))
877 void
tcp_log_th_flags(void * hdr,struct tcphdr * th,struct tcpcb * tp,bool outgoing,struct ifnet * ifp)878 tcp_log_th_flags(void *hdr, struct tcphdr *th, struct tcpcb *tp, bool outgoing, struct ifnet *ifp)
879 {
880 	struct inpcb *inp = tp->t_inpcb;
881 	struct socket *so = inp != NULL ? inp->inp_socket : NULL;
882 	char laddr_buf[ADDRESS_STR_LEN];
883 	char faddr_buf[ADDRESS_STR_LEN];
884 	in_port_t local_port;
885 	in_port_t foreign_port;
886 	uint8_t thflags;
887 
888 	if (hdr == NULL || th == NULL) {
889 		return;
890 	}
891 
892 	thflags = th->th_flags;
893 
894 	if (should_log_th_flags(thflags, tp, outgoing, ifp) == false) {
895 		return;
896 	}
897 
898 	if (outgoing) {
899 		local_port = th->th_sport;
900 		foreign_port = th->th_dport;
901 	} else {
902 		local_port = th->th_dport;
903 		foreign_port = th->th_sport;
904 	}
905 	if (!tcp_log_pkt_addresses(hdr, th, outgoing, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf))) {
906 		return;
907 	}
908 
909 	/* Do not log too much */
910 	if (tcp_log_is_rate_limited()) {
911 		return;
912 	}
913 
914 	/*
915 	 * When no PCB or socket just log the packet
916 	 */
917 	if (tp == NULL || so == NULL || inp == NULL) {
918 #define TCP_LOG_TH_FLAGS_NO_PCB_FMT \
919 	    TCP_LOG_TH_FLAGS_COMMON_FMT \
920 	    TCP_LOG_COMMON_FMT
921 #define TCP_LOG_TH_FLAGS_NO_PCB_ARGS \
922 	    TCP_LOG_TH_FLAGS_COMMON_ARGS, \
923 	    TCP_LOG_COMMON_ARGS
924 
925 		os_log(OS_LOG_DEFAULT, TCP_LOG_TH_FLAGS_NO_PCB_FMT,
926 		    TCP_LOG_TH_FLAGS_NO_PCB_ARGS);
927 #undef TCP_LOG_TH_FLAGS_NO_PCB_FMT
928 #undef TCP_LOG_TH_FLAGS_NO_PCB_ARGS
929 	} else {
930 #define TCP_LOG_TH_FLAGS_PCB_FMT \
931 	    TCP_LOG_TH_FLAGS_COMMON_FMT \
932 	    TCP_LOG_COMMON_PCB_FMT \
933 	    "SYN in/out: %u/%u "
934 
935 #define TCP_LOG_TH_FLAGS_PCB_ARGS \
936 	    TCP_LOG_TH_FLAGS_COMMON_ARGS, \
937 	    TCP_LOG_COMMON_PCB_ARGS, \
938 	    tp->t_syn_rcvd, tp->t_syn_sent
939 
940 		os_log(OS_LOG_DEFAULT, TCP_LOG_TH_FLAGS_PCB_FMT,
941 		    TCP_LOG_TH_FLAGS_PCB_ARGS);
942 #undef TCP_LOG_TH_FLAGS_PCB_FMT
943 #undef TCP_LOG_TH_FLAGS_PCB_ARGS
944 	}
945 }
946 
947 __attribute__((noinline))
948 void
tcp_log_drop_pkt(void * hdr,struct tcphdr * th,struct ifnet * ifp,const char * reason)949 tcp_log_drop_pkt(void *hdr, struct tcphdr *th, struct ifnet *ifp, const char *reason)
950 {
951 	char laddr_buf[ADDRESS_STR_LEN];
952 	char faddr_buf[ADDRESS_STR_LEN];
953 	in_port_t local_port;
954 	in_port_t foreign_port;
955 	uint8_t thflags;
956 	bool outgoing = false;  /* This is only for incoming packets */
957 
958 	if (hdr == NULL || th == NULL) {
959 		return;
960 	}
961 
962 	local_port = th->th_dport;
963 	foreign_port = th->th_sport;
964 	thflags = th->th_flags;
965 
966 	if (should_log_th_flags(thflags, NULL, outgoing, ifp) == false) {
967 		return;
968 	}
969 
970 	if (!tcp_log_pkt_addresses(hdr, th, outgoing, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf))) {
971 		return;
972 	}
973 
974 	/* Do not log too much */
975 	if (tcp_log_is_rate_limited()) {
976 		return;
977 	}
978 
979 #define TCP_LOG_DROP_PKT_FMT \
980 	    "tcp drop incoming control packet " \
981 	        TCP_LOG_TH_FLAGS_COMMON_FMT \
982 	    "reason: %s"
983 
984 #define TCP_LOG_DROP_PKT_ARGS \
985 	    TCP_LOG_TH_FLAGS_COMMON_ARGS, \
986 	    reason != NULL ? reason : ""
987 
988 	os_log(OS_LOG_DEFAULT, TCP_LOG_DROP_PKT_FMT,
989 	    TCP_LOG_DROP_PKT_ARGS);
990 #undef TCP_LOG_DROP_PKT_FMT
991 #undef TCP_LOG_DROP_PKT_ARGS
992 }
993 
994 __attribute__((noinline))
995 void
tcp_log_message(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)996 tcp_log_message(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
997 {
998 	struct inpcb *inp;
999 	struct socket *so;
1000 	struct ifnet *ifp;
1001 	char laddr_buf[ADDRESS_STR_LEN];
1002 	char faddr_buf[ADDRESS_STR_LEN];
1003 	in_port_t local_port;
1004 	in_port_t foreign_port;
1005 	char message[256];
1006 
1007 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1008 		return;
1009 	}
1010 
1011 	/* Do not log too much */
1012 	if (tcp_log_is_rate_limited()) {
1013 		return;
1014 	}
1015 	inp = tp->t_inpcb;
1016 	so = inp->inp_socket;
1017 
1018 	local_port = inp->inp_lport;
1019 	foreign_port = inp->inp_fport;
1020 
1021 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1022 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1023 
1024 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1025 
1026 	va_list ap;
1027 	va_start(ap, format);
1028 	vsnprintf(message, sizeof(message), format, ap);
1029 	va_end(ap);
1030 
1031 #define TCP_LOG_MESSAGE_FMT \
1032 	"tcp (%s:%d) " \
1033 	TCP_LOG_COMMON_PCB_FMT \
1034 	"bytes in/out: %llu/%llu " \
1035 	"pkts in/out: %llu/%llu " \
1036 	"%s"
1037 
1038 #define TCP_LOG_MESSAGE_ARGS \
1039 	func_name, line_no, \
1040 	TCP_LOG_COMMON_PCB_ARGS, \
1041 	inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
1042 	inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
1043 	message
1044 
1045 	os_log(OS_LOG_DEFAULT, TCP_LOG_MESSAGE_FMT,
1046 	    TCP_LOG_MESSAGE_ARGS);
1047 #undef TCP_LOG_MESSAGE_FMT
1048 #undef TCP_LOG_MESSAGE_ARGS
1049 }
1050 
1051 #if SKYWALK
1052 __attribute__((noinline))
1053 void
tcp_log_fsw_flow(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)1054 tcp_log_fsw_flow(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
1055 {
1056 	struct inpcb *inp;
1057 	struct socket *so;
1058 	struct ifnet *ifp;
1059 	char laddr_buf[ADDRESS_STR_LEN];
1060 	char faddr_buf[ADDRESS_STR_LEN];
1061 	in_port_t local_port;
1062 	in_port_t foreign_port;
1063 	uuid_string_t flow_uuid_str;
1064 	char message[256];
1065 
1066 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1067 		return;
1068 	}
1069 
1070 	/* Do not log too much */
1071 	if (tcp_log_is_rate_limited()) {
1072 		return;
1073 	}
1074 	inp = tp->t_inpcb;
1075 	so = inp->inp_socket;
1076 
1077 	local_port = inp->inp_lport;
1078 	foreign_port = inp->inp_fport;
1079 
1080 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1081 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1082 
1083 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1084 
1085 	uuid_unparse_upper(tp->t_flow_uuid, flow_uuid_str);
1086 
1087 	va_list ap;
1088 	va_start(ap, format);
1089 	vsnprintf(message, sizeof(message), format, ap);
1090 	va_end(ap);
1091 
1092 #define TCP_LOG_FSW_FLOW_MESSAGE_FMT \
1093 	"tcp (%s:%d) " \
1094 	TCP_LOG_COMMON_PCB_FMT \
1095 	"flow %s %s"
1096 
1097 #define TCP_LOG_FSW_FLOW_MESSAGE_ARGS \
1098 	func_name, line_no, \
1099 	TCP_LOG_COMMON_PCB_ARGS, \
1100 	flow_uuid_str, \
1101 	message
1102 
1103 	os_log(OS_LOG_DEFAULT, TCP_LOG_FSW_FLOW_MESSAGE_FMT,
1104 	    TCP_LOG_FSW_FLOW_MESSAGE_ARGS);
1105 #undef TCP_LOG_FSW_FLOW_MESSAGE_FMT
1106 #undef TCP_LOG_FSW_FLOW_MESSAGE_ARGS
1107 }
1108 #endif /* SKYWALK */
1109 
1110 void
tcp_log_state_change(const char * func_name,int line_no,struct tcpcb * tp,int new_state)1111 tcp_log_state_change(const char *func_name, int line_no, struct tcpcb *tp, int new_state)
1112 {
1113 	struct inpcb *inp;
1114 	struct socket *so;
1115 	struct ifnet *ifp;
1116 	char laddr_buf[ADDRESS_STR_LEN];
1117 	char faddr_buf[ADDRESS_STR_LEN];
1118 	in_port_t local_port;
1119 	in_port_t foreign_port;
1120 
1121 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1122 		return;
1123 	}
1124 	if (new_state == tp->t_state) {
1125 		return;
1126 	}
1127 
1128 	/* Do not log too much */
1129 	if (tcp_log_is_rate_limited()) {
1130 		return;
1131 	}
1132 
1133 	inp = tp->t_inpcb;
1134 	so = inp->inp_socket;
1135 
1136 	local_port = inp->inp_lport;
1137 	foreign_port = inp->inp_fport;
1138 
1139 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1140 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1141 
1142 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1143 
1144 #define TCP_LOG_STATE_FMT \
1145 	    "tcp_state_changed (%s:%d) " \
1146 	    TCP_LOG_COMMON_PCB_FMT \
1147 	    "%s "
1148 
1149 #define TCP_LOG_STATE_ARGS \
1150 	func_name, line_no, \
1151 	TCP_LOG_COMMON_PCB_ARGS, \
1152 	tcpstates[new_state] \
1153 
1154 	os_log(OS_LOG_DEFAULT, TCP_LOG_STATE_FMT,
1155 	    TCP_LOG_STATE_ARGS);
1156 #undef TCP_LOG_STATE_FMT
1157 #undef TCP_LOG_STATE_ARGS
1158 }
1159 
1160 __attribute__((noinline))
1161 void
tcp_log_output(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)1162 tcp_log_output(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
1163 {
1164 	struct inpcb *inp;
1165 	struct socket *so;
1166 	struct ifnet *ifp;
1167 	char laddr_buf[ADDRESS_STR_LEN];
1168 	char faddr_buf[ADDRESS_STR_LEN];
1169 	in_port_t local_port;
1170 	in_port_t foreign_port;
1171 	char message[256];
1172 
1173 	if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1174 		return;
1175 	}
1176 	/* Log only when fron send() or connect() */
1177 	if ((tp->t_flagsext & TF_USR_OUTPUT) == 0) {
1178 		return;
1179 	}
1180 	/* Do not log too much */
1181 	if (tcp_log_is_rate_limited()) {
1182 		return;
1183 	}
1184 	inp = tp->t_inpcb;
1185 	so = inp->inp_socket;
1186 
1187 	local_port = inp->inp_lport;
1188 	foreign_port = inp->inp_fport;
1189 
1190 	ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1191 	    inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1192 
1193 	tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1194 
1195 	va_list ap;
1196 	va_start(ap, format);
1197 	vsnprintf(message, sizeof(message), format, ap);
1198 	va_end(ap);
1199 
1200 #define TCP_LOG_MESSAGE_FMT \
1201 	"tcp (%s:%d) " \
1202 	TCP_LOG_COMMON_PCB_FMT \
1203 	"bytes in/out: %llu/%llu " \
1204 	"pkts in/out: %llu/%llu " \
1205 	"rxmit pkts/bytes: %u/%u" \
1206 	"%s"
1207 
1208 #define TCP_LOG_MESSAGE_ARGS \
1209 	func_name, line_no, \
1210 	TCP_LOG_COMMON_PCB_ARGS, \
1211 	inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
1212 	inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
1213 	tp->t_stat.rxmitpkts, tp->t_stat.txretransmitbytes, \
1214 	message
1215 
1216 	os_log(OS_LOG_DEFAULT, TCP_LOG_MESSAGE_FMT,
1217 	    TCP_LOG_MESSAGE_ARGS);
1218 #undef TCP_LOG_MESSAGE_FMT
1219 #undef TCP_LOG_MESSAGE_ARGS
1220 }
1221 
1222 static int
1223 sysctl_tcp_log_port SYSCTL_HANDLER_ARGS
1224 {
1225 #pragma unused(arg1, arg2)
1226 	int i, error;
1227 
1228 	i = tcp_log_port;
1229 
1230 	error = sysctl_handle_int(oidp, &i, 0, req);
1231 	if (error) {
1232 		return error;
1233 	}
1234 
1235 	if (i < 0 || i > UINT16_MAX) {
1236 		return EINVAL;
1237 	}
1238 
1239 	tcp_log_port = (uint16_t)i;
1240 	return 0;
1241 }
1242