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