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