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 local_port = inp->inp_lport;
396 foreign_port = inp->inp_fport;
397
398 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
399 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
400
401 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
402
403 #define TCP_LOG_CONNECT_FMT \
404 "tcp %s: " \
405 TCP_LOG_COMMON_PCB_FMT \
406 "SYN in/out: %u/%u " \
407 "bytes in/out: %llu/%llu " \
408 "pkts in/out: %llu/%llu " \
409 "rtt: %u.%u ms " \
410 "rttvar: %u.%u ms " \
411 "base_rtt: %u ms " \
412 "error: %d " \
413 "so_error: %d " \
414 "svc/tc: %u " \
415 "flow: 0x%x"
416
417 #define TCP_LOG_CONNECT_ARGS \
418 event, \
419 TCP_LOG_COMMON_PCB_ARGS, \
420 tp->t_syn_rcvd, tp->t_syn_sent, \
421 inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
422 inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
423 P_MS(tp->t_srtt, TCP_RTT_SHIFT), \
424 P_MS(tp->t_rttvar, TCP_RTTVAR_SHIFT), \
425 get_base_rtt(tp), \
426 error, \
427 so->so_error, \
428 (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \
429 inp->inp_flowhash
430
431 if (so->so_head == NULL) {
432 os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECT_FMT,
433 TCP_LOG_CONNECT_ARGS);
434 } else {
435 #define TCP_LOG_CONN_Q_FMT \
436 "so_qlimit: %d "\
437 "so_qlen: %d "\
438 "so_incqlen: %d "
439
440 #define TCP_LOG_CONN_Q_ARGS \
441 so->so_head->so_qlimit, \
442 so->so_head->so_qlen, \
443 so->so_head->so_incqlen
444
445 os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECT_FMT "\n" TCP_LOG_CONN_Q_FMT,
446 TCP_LOG_CONNECT_ARGS, TCP_LOG_CONN_Q_ARGS);
447 #undef TCP_LOG_CONN_Q_FMT
448 #undef TCP_LOG_CONN_Q_ARGS
449 }
450 #undef TCP_LOG_CONNECT_FMT
451 #undef TCP_LOG_CONNECT_ARGS
452 }
453
454 __attribute__((noinline))
455 void
tcp_log_listen(struct tcpcb * tp,int error)456 tcp_log_listen(struct tcpcb *tp, int error)
457 {
458 struct inpcb *inp = tp->t_inpcb;
459 struct socket *so = inp->inp_socket;
460 struct ifnet *ifp;
461 char laddr_buf[ADDRESS_STR_LEN];
462 char faddr_buf[ADDRESS_STR_LEN];
463 in_port_t local_port;
464 in_port_t foreign_port;
465
466 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
467 return;
468 }
469
470 /* Do not log too much */
471 if (tcp_log_is_rate_limited()) {
472 return;
473 }
474 inp = tp->t_inpcb;
475 so = inp->inp_socket;
476
477 local_port = inp->inp_lport;
478 foreign_port = inp->inp_fport;
479
480 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
481 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
482
483 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
484
485 #define TCP_LOG_LISTEN_FMT \
486 "tcp listen: " \
487 TCP_LOG_COMMON_PCB_FMT \
488 "so_qlimit: %d "\
489 "error: %d " \
490 "so_error: %d " \
491 "svc/tc: %u"
492
493 #define TCP_LOG_LISTEN_ARGS \
494 TCP_LOG_COMMON_PCB_ARGS, \
495 so->so_qlimit, \
496 error, \
497 so->so_error, \
498 (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class
499
500 os_log(OS_LOG_DEFAULT, TCP_LOG_LISTEN_FMT,
501 TCP_LOG_LISTEN_ARGS);
502 #undef TCP_LOG_LISTEN_FMT
503 #undef TCP_LOG_LISTEN_ARGS
504 }
505
506 static const char *
tcp_connection_client_accurate_ecn_state_to_string(tcp_connection_client_accurate_ecn_state_t state)507 tcp_connection_client_accurate_ecn_state_to_string(tcp_connection_client_accurate_ecn_state_t state)
508 {
509 switch (state) {
510 #define ECN_STATE_TO_STRING(_s, _str) \
511 case tcp_connection_client_accurate_ecn_##_s: { \
512 return _str; \
513 }
514 ECN_STATE_TO_STRING(invalid, "Invalid")
515 ECN_STATE_TO_STRING(feature_disabled, "Disabled")
516 ECN_STATE_TO_STRING(feature_enabled, "Enabled")
517 ECN_STATE_TO_STRING(negotiation_blackholed, "Blackholed")
518 ECN_STATE_TO_STRING(ace_bleaching_detected, "ACE bleaching")
519 ECN_STATE_TO_STRING(negotiation_success, "Capable")
520 ECN_STATE_TO_STRING(negotiation_success_ect_mangling_detected, "ECT mangling")
521 ECN_STATE_TO_STRING(negotiation_success_ect_bleaching_detected, "ECT bleaching")
522 #undef ECN_STATE_TO_STRING
523 case tcp_connection_client_classic_ecn_available:
524 return "Classic ECN";
525 case tcp_connection_client_ecn_not_available:
526 return "Unavailable";
527 }
528 return "Unknown";
529 }
530
531 static const char *
tcp_connection_server_accurate_ecn_state_to_string(tcp_connection_server_accurate_ecn_state_t state)532 tcp_connection_server_accurate_ecn_state_to_string(tcp_connection_server_accurate_ecn_state_t state)
533 {
534 switch (state) {
535 #define ECN_STATE_TO_STRING(_s, _str) \
536 case tcp_connection_server_accurate_ecn_##_s: { \
537 return _str; \
538 }
539 ECN_STATE_TO_STRING(invalid, "Invalid")
540 ECN_STATE_TO_STRING(feature_disabled, "Disabled")
541 ECN_STATE_TO_STRING(feature_enabled, "Enabled")
542 ECN_STATE_TO_STRING(requested, "Requested")
543 ECN_STATE_TO_STRING(negotiation_blackholed, "Blackholed")
544 ECN_STATE_TO_STRING(ace_bleaching_detected, "ACE bleaching")
545 ECN_STATE_TO_STRING(negotiation_success, "Capable")
546 ECN_STATE_TO_STRING(negotiation_success_ect_mangling_detected, "ECT mangling")
547 ECN_STATE_TO_STRING(negotiation_success_ect_bleaching_detected, "ECT bleaching")
548 #undef ECN_STATE_TO_STRING
549 case tcp_connection_server_no_ecn_requested:
550 return "Not requested";
551 case tcp_connection_server_classic_ecn_requested:
552 return "Classic ECN requested";
553 }
554 return "Unknown";
555 }
556
557 __attribute__((noinline))
558 void
tcp_log_connection_summary(struct tcpcb * tp)559 tcp_log_connection_summary(struct tcpcb *tp)
560 {
561 struct inpcb *inp;
562 struct socket *so;
563 struct ifnet *ifp;
564 uint32_t conntime = 0;
565 uint32_t duration = 0;
566 char laddr_buf[ADDRESS_STR_LEN];
567 char faddr_buf[ADDRESS_STR_LEN];
568 in_port_t local_port;
569 in_port_t foreign_port;
570
571 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
572 return;
573 }
574
575 /* Do not log too much */
576 if (tcp_log_is_rate_limited()) {
577 return;
578 }
579 inp = tp->t_inpcb;
580 so = inp->inp_socket;
581
582 local_port = inp->inp_lport;
583 foreign_port = inp->inp_fport;
584
585 /* Make sure the summary is logged once */
586 if (inp->inp_flags2 & INP2_LOGGED_SUMMARY) {
587 return;
588 }
589 inp->inp_flags2 |= INP2_LOGGED_SUMMARY;
590
591 /*
592 * t_connect_time is the time when the connection started on
593 * the first SYN.
594 *
595 * t_starttime is when the three way handshake was completed.
596 */
597 if (tp->t_connect_time > 0) {
598 duration = tcp_now - tp->t_connect_time;
599
600 if (tp->t_starttime > 0) {
601 conntime = tp->t_starttime - tp->t_connect_time;
602 }
603 }
604
605 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
606 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
607
608 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
609
610 /*
611 * Need to use 2 log messages because the size of the summary
612 */
613
614 #define TCP_LOG_CONNECTION_SUMMARY_FMT \
615 "tcp_connection_summary " \
616 TCP_LOG_COMMON_PCB_FMT \
617 "Duration: %u.%03u sec " \
618 "Conn_Time: %u.%03u sec " \
619 "bytes in/out: %llu/%llu " \
620 "pkts in/out: %llu/%llu " \
621 "pkt rxmit: %u " \
622 "ooo pkts: %u dup bytes in: %u ACKs delayed: %u delayed ACKs sent: %u\n" \
623 "rtt: %u.%03u ms " \
624 "rttvar: %u.%03u ms " \
625 "base rtt: %u ms " \
626 "so_error: %d " \
627 "svc/tc: %u " \
628 "flow: 0x%x"
629
630 #define TCP_LOG_CONNECTION_SUMMARY_ARGS \
631 TCP_LOG_COMMON_PCB_ARGS, \
632 duration / TCP_RETRANSHZ, duration % TCP_RETRANSHZ, \
633 conntime / TCP_RETRANSHZ, conntime % TCP_RETRANSHZ, \
634 inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
635 inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
636 tp->t_stat.rxmitpkts, \
637 tp->t_rcvoopack, tp->t_stat.rxduplicatebytes, tp->t_stat.acks_delayed, tp->t_stat.delayed_acks_sent, \
638 P_MS(tp->t_srtt, TCP_RTT_SHIFT), \
639 P_MS(tp->t_rttvar, TCP_RTTVAR_SHIFT), \
640 get_base_rtt(tp), \
641 so->so_error, \
642 (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \
643 inp->inp_flowhash
644
645 os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECTION_SUMMARY_FMT,
646 TCP_LOG_CONNECTION_SUMMARY_ARGS);
647 #undef TCP_LOG_CONNECTION_SUMMARY_FMT
648 #undef TCP_LOG_CONNECTION_SUMMARY_ARGS
649
650 #define TCP_LOG_CONNECTION_SUMMARY_FMT \
651 "tcp_connection_summary " \
652 TCP_LOG_COMMON_PCB_FMT \
653 "flowctl: %lluus (%llux) " \
654 "SYN in/out: %u/%u " \
655 "FIN in/out: %u/%u " \
656 "RST in/out: %u/%u " \
657 "AccECN (client/server): %s/%s\n" \
658
659 #define TCP_LOG_CONNECTION_SUMMARY_ARGS \
660 TCP_LOG_COMMON_PCB_ARGS, \
661 inp->inp_fadv_total_time, \
662 inp->inp_fadv_cnt, \
663 tp->t_syn_rcvd, tp->t_syn_sent, \
664 tp->t_fin_rcvd, tp->t_fin_sent, \
665 tp->t_rst_rcvd, tp->t_rst_sent, \
666 tcp_connection_client_accurate_ecn_state_to_string(tp->t_client_accecn_state), \
667 tcp_connection_server_accurate_ecn_state_to_string(tp->t_server_accecn_state)
668
669 os_log(OS_LOG_DEFAULT, TCP_LOG_CONNECTION_SUMMARY_FMT,
670 TCP_LOG_CONNECTION_SUMMARY_ARGS);
671 #undef TCP_LOG_CONNECTION_SUMMARY_FMT
672 #undef TCP_LOG_CONNECTION_SUMMARY_ARGS
673 }
674
675 __attribute__((noinline))
676 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)677 tcp_log_pkt_addresses(void *hdr, struct tcphdr *th, bool outgoing,
678 char *__sized_by(lbuflen) lbuf, socklen_t lbuflen,
679 char *__sized_by(fbuflen) fbuf, socklen_t fbuflen)
680 {
681 bool isipv6;
682 uint8_t thflags;
683
684 isipv6 = (((struct ip *)hdr)->ip_v == 6);
685 thflags = th->th_flags;
686
687 if (isipv6) {
688 struct ip6_hdr *ip6 = (struct ip6_hdr *)hdr;
689 struct in6_addr src_addr6 = ip6->ip6_src;
690 struct in6_addr dst_addr6 = ip6->ip6_dst;
691
692 #pragma clang diagnostic push
693 #pragma clang diagnostic ignored "-Waddress-of-packed-member"
694 if (memcmp(&src_addr6, &in6addr_loopback, sizeof(struct in6_addr)) == 0 ||
695 memcmp(&dst_addr6, &in6addr_loopback, sizeof(struct in6_addr)) == 0) {
696 if (!(tcp_log_enable_flags & TLEF_DST_LOOPBACK)) {
697 return false;
698 }
699 }
700 #pragma clang diagnostic pop
701
702 if (IN6_IS_ADDR_LINKLOCAL(&src_addr6)) {
703 src_addr6.s6_addr16[1] = 0;
704 }
705 if (IN6_IS_ADDR_LINKLOCAL(&dst_addr6)) {
706 dst_addr6.s6_addr16[1] = 0;
707 }
708
709 if (inp_log_privacy != 0) {
710 strlcpy(lbuf, "<IPv6-redacted>", lbuflen);
711 strlcpy(fbuf, "<IPv6-redacted>", fbuflen);
712 } else if (outgoing) {
713 inet_ntop(AF_INET6, &src_addr6, lbuf, lbuflen);
714 inet_ntop(AF_INET6, &dst_addr6, fbuf, fbuflen);
715 } else {
716 inet_ntop(AF_INET6, &dst_addr6, lbuf, lbuflen);
717 inet_ntop(AF_INET6, &src_addr6, fbuf, fbuflen);
718 }
719 } else {
720 struct ip *ip = (struct ip *)hdr;
721
722 if (ntohl(ip->ip_src.s_addr) == INADDR_LOOPBACK ||
723 ntohl(ip->ip_dst.s_addr) == INADDR_LOOPBACK) {
724 if (!(tcp_log_enable_flags & TLEF_DST_LOOPBACK)) {
725 return false;
726 }
727 }
728
729 if (inp_log_privacy != 0) {
730 strlcpy(lbuf, "<IPv4-redacted>", lbuflen);
731 strlcpy(fbuf, "<IPv4-redacted>", fbuflen);
732 } else if (outgoing) {
733 inet_ntop(AF_INET, (void *)&ip->ip_src.s_addr, lbuf, lbuflen);
734 inet_ntop(AF_INET, (void *)&ip->ip_dst.s_addr, fbuf, fbuflen);
735 } else {
736 inet_ntop(AF_INET, (void *)&ip->ip_dst.s_addr, lbuf, lbuflen);
737 inet_ntop(AF_INET, (void *)&ip->ip_src.s_addr, fbuf, fbuflen);
738 }
739 }
740 return true;
741 }
742
743 /*
744 * Note: currently only used in the input path
745 */
746 __attribute__((noinline))
747 void
tcp_log_drop_pcb(void * hdr,struct tcphdr * th,struct tcpcb * tp,bool outgoing,const char * reason)748 tcp_log_drop_pcb(void *hdr, struct tcphdr *th, struct tcpcb *tp, bool outgoing, const char *reason)
749 {
750 struct inpcb *inp;
751 struct socket *so;
752 struct ifnet *ifp;
753 char laddr_buf[ADDRESS_STR_LEN];
754 char faddr_buf[ADDRESS_STR_LEN];
755 in_port_t local_port;
756 in_port_t foreign_port;
757 const char *direction = "";
758
759 if (tp == NULL) {
760 return;
761 }
762 inp = tp->t_inpcb;
763 if (inp == NULL) {
764 return;
765 }
766 so = inp->inp_socket;
767 if (so == NULL) {
768 return;
769 }
770
771 /* Do not log common drops after the connection termination is logged */
772 if ((inp->inp_flags2 & INP2_LOGGED_SUMMARY) && ((so->so_state & SS_NOFDREF) ||
773 (so->so_flags & SOF_DEFUNCT) || (so->so_state & SS_CANTRCVMORE))) {
774 return;
775 }
776
777 /* Do not log too much */
778 if (tcp_log_is_rate_limited()) {
779 return;
780 }
781
782 /* Use the packet addresses when in the data path */
783 if (hdr != NULL && th != NULL) {
784 if (outgoing) {
785 local_port = th->th_sport;
786 foreign_port = th->th_dport;
787 direction = "outgoing ";
788 } else {
789 local_port = th->th_dport;
790 foreign_port = th->th_sport;
791 direction = "incoming ";
792 }
793 (void) tcp_log_pkt_addresses(hdr, th, outgoing, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
794 } else {
795 local_port = inp->inp_lport;
796 foreign_port = inp->inp_fport;
797 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
798 }
799
800 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
801 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
802
803 #define TCP_LOG_DROP_PCB_FMT \
804 "tcp drop %s" \
805 TCP_LOG_COMMON_PCB_FMT \
806 "t_state: %s " \
807 "so_error: %d " \
808 "reason: %s"
809
810 #define TCP_LOG_DROP_PCB_ARGS \
811 direction, \
812 TCP_LOG_COMMON_PCB_ARGS, \
813 tcpstates[tp->t_state], \
814 so->so_error, \
815 reason
816
817 os_log(OS_LOG_DEFAULT, TCP_LOG_DROP_PCB_FMT,
818 TCP_LOG_DROP_PCB_ARGS);
819 #undef TCP_LOG_DROP_PCB_FMT
820 #undef TCP_LOG_DROP_PCB_ARGS
821 }
822
823 #define TCP_LOG_TH_FLAGS_COMMON_FMT \
824 "tcp control %s " \
825 "%s" \
826 "%s" \
827 "%s" \
828 "%s"
829
830 #define TCP_LOG_TH_FLAGS_COMMON_ARGS \
831 outgoing ? "outgoing" : "incoming", \
832 thflags & TH_SYN ? "SYN " : "", \
833 thflags & TH_FIN ? "FIN " : "", \
834 thflags & TH_RST ? "RST " : "", \
835 thflags & TH_ACK ? "ACK " : ""
836
837 static bool
should_log_th_flags(uint8_t thflags,struct tcpcb * tp,bool outgoing,struct ifnet * ifp)838 should_log_th_flags(uint8_t thflags, struct tcpcb *tp, bool outgoing, struct ifnet *ifp)
839 {
840 /*
841 * Check logging is enabled for interface for TCP control packets
842 *
843 * Note: the type of tcp_log_thflags_if_family is uint64_t but we
844 * access its value as bit string so we have to pay extra care to avoid
845 * out of bound access
846 */
847 if (ifp != NULL && (ifp->if_family >= (sizeof(tcp_log_thflags_if_family) << 3) ||
848 !bitstr_test((bitstr_t *)&tcp_log_thflags_if_family, ifp->if_family))) {
849 return false;
850 }
851 /*
852 * Log when seeing 3 SYN retransmissions of more on a TCP PCB
853 */
854 if (tp != NULL &&
855 ((thflags & TH_SYN) && (tcp_log_enable_flags & TLEF_SYN_RXMT) &&
856 ((outgoing && tp->t_syn_sent > 3) || (!outgoing && tp->t_syn_rcvd > 3)))) {
857 return true;
858 }
859 /*
860 * Log control packet when enabled
861 */
862 if ((((thflags & TH_SYN) && (tcp_log_enable_flags & TLEF_THF_SYN)) ||
863 ((thflags & TH_FIN) && (tcp_log_enable_flags & TLEF_THF_FIN)) ||
864 ((thflags & TH_RST) && (tcp_log_enable_flags & TLEF_THF_RST)))) {
865 return true;
866 }
867 return false;
868 }
869
870 __attribute__((noinline))
871 void
tcp_log_th_flags(void * hdr,struct tcphdr * th,struct tcpcb * tp,bool outgoing,struct ifnet * ifp)872 tcp_log_th_flags(void *hdr, struct tcphdr *th, struct tcpcb *tp, bool outgoing, struct ifnet *ifp)
873 {
874 struct inpcb *inp = tp->t_inpcb;
875 struct socket *so = inp != NULL ? inp->inp_socket : NULL;
876 char laddr_buf[ADDRESS_STR_LEN];
877 char faddr_buf[ADDRESS_STR_LEN];
878 in_port_t local_port;
879 in_port_t foreign_port;
880 uint8_t thflags;
881
882 if (hdr == NULL || th == NULL) {
883 return;
884 }
885
886 thflags = th->th_flags;
887
888 if (should_log_th_flags(thflags, tp, outgoing, ifp) == false) {
889 return;
890 }
891
892 if (outgoing) {
893 local_port = th->th_sport;
894 foreign_port = th->th_dport;
895 } else {
896 local_port = th->th_dport;
897 foreign_port = th->th_sport;
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 /*
909 * When no PCB or socket just log the packet
910 */
911 if (tp == NULL || so == NULL || inp == NULL) {
912 #define TCP_LOG_TH_FLAGS_NO_PCB_FMT \
913 TCP_LOG_TH_FLAGS_COMMON_FMT \
914 TCP_LOG_COMMON_FMT
915 #define TCP_LOG_TH_FLAGS_NO_PCB_ARGS \
916 TCP_LOG_TH_FLAGS_COMMON_ARGS, \
917 TCP_LOG_COMMON_ARGS
918
919 os_log(OS_LOG_DEFAULT, TCP_LOG_TH_FLAGS_NO_PCB_FMT,
920 TCP_LOG_TH_FLAGS_NO_PCB_ARGS);
921 #undef TCP_LOG_TH_FLAGS_NO_PCB_FMT
922 #undef TCP_LOG_TH_FLAGS_NO_PCB_ARGS
923 } else {
924 #define TCP_LOG_TH_FLAGS_PCB_FMT \
925 TCP_LOG_TH_FLAGS_COMMON_FMT \
926 TCP_LOG_COMMON_PCB_FMT \
927 "SYN in/out: %u/%u "
928
929 #define TCP_LOG_TH_FLAGS_PCB_ARGS \
930 TCP_LOG_TH_FLAGS_COMMON_ARGS, \
931 TCP_LOG_COMMON_PCB_ARGS, \
932 tp->t_syn_rcvd, tp->t_syn_sent
933
934 os_log(OS_LOG_DEFAULT, TCP_LOG_TH_FLAGS_PCB_FMT,
935 TCP_LOG_TH_FLAGS_PCB_ARGS);
936 #undef TCP_LOG_TH_FLAGS_PCB_FMT
937 #undef TCP_LOG_TH_FLAGS_PCB_ARGS
938 }
939 }
940
941 __attribute__((noinline))
942 void
tcp_log_drop_pkt(void * hdr,struct tcphdr * th,struct ifnet * ifp,const char * reason)943 tcp_log_drop_pkt(void *hdr, struct tcphdr *th, struct ifnet *ifp, const char *reason)
944 {
945 char laddr_buf[ADDRESS_STR_LEN];
946 char faddr_buf[ADDRESS_STR_LEN];
947 in_port_t local_port;
948 in_port_t foreign_port;
949 uint8_t thflags;
950 bool outgoing = false; /* This is only for incoming packets */
951
952 if (hdr == NULL || th == NULL) {
953 return;
954 }
955
956 local_port = th->th_dport;
957 foreign_port = th->th_sport;
958 thflags = th->th_flags;
959
960 if (should_log_th_flags(thflags, NULL, outgoing, ifp) == false) {
961 return;
962 }
963
964 if (!tcp_log_pkt_addresses(hdr, th, outgoing, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf))) {
965 return;
966 }
967
968 /* Do not log too much */
969 if (tcp_log_is_rate_limited()) {
970 return;
971 }
972
973 #define TCP_LOG_DROP_PKT_FMT \
974 "tcp drop incoming control packet " \
975 TCP_LOG_TH_FLAGS_COMMON_FMT \
976 "reason: %s"
977
978 #define TCP_LOG_DROP_PKT_ARGS \
979 TCP_LOG_TH_FLAGS_COMMON_ARGS, \
980 reason != NULL ? reason : ""
981
982 os_log(OS_LOG_DEFAULT, TCP_LOG_DROP_PKT_FMT,
983 TCP_LOG_DROP_PKT_ARGS);
984 #undef TCP_LOG_DROP_PKT_FMT
985 #undef TCP_LOG_DROP_PKT_ARGS
986 }
987
988 __attribute__((noinline))
989 void
tcp_log_message(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)990 tcp_log_message(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
991 {
992 struct inpcb *inp;
993 struct socket *so;
994 struct ifnet *ifp;
995 char laddr_buf[ADDRESS_STR_LEN];
996 char faddr_buf[ADDRESS_STR_LEN];
997 in_port_t local_port;
998 in_port_t foreign_port;
999 char message[256];
1000
1001 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1002 return;
1003 }
1004
1005 /* Do not log too much */
1006 if (tcp_log_is_rate_limited()) {
1007 return;
1008 }
1009 inp = tp->t_inpcb;
1010 so = inp->inp_socket;
1011
1012 local_port = inp->inp_lport;
1013 foreign_port = inp->inp_fport;
1014
1015 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1016 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1017
1018 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1019
1020 va_list ap;
1021 va_start(ap, format);
1022 vsnprintf(message, sizeof(message), format, ap);
1023 va_end(ap);
1024
1025 #define TCP_LOG_MESSAGE_FMT \
1026 "tcp (%s:%d) " \
1027 TCP_LOG_COMMON_PCB_FMT \
1028 "bytes in/out: %llu/%llu " \
1029 "pkts in/out: %llu/%llu " \
1030 "%s"
1031
1032 #define TCP_LOG_MESSAGE_ARGS \
1033 func_name, line_no, \
1034 TCP_LOG_COMMON_PCB_ARGS, \
1035 inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
1036 inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
1037 message
1038
1039 os_log(OS_LOG_DEFAULT, TCP_LOG_MESSAGE_FMT,
1040 TCP_LOG_MESSAGE_ARGS);
1041 #undef TCP_LOG_MESSAGE_FMT
1042 #undef TCP_LOG_MESSAGE_ARGS
1043 }
1044
1045 #if SKYWALK
1046 __attribute__((noinline))
1047 void
tcp_log_fsw_flow(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)1048 tcp_log_fsw_flow(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
1049 {
1050 struct inpcb *inp;
1051 struct socket *so;
1052 struct ifnet *ifp;
1053 char laddr_buf[ADDRESS_STR_LEN];
1054 char faddr_buf[ADDRESS_STR_LEN];
1055 in_port_t local_port;
1056 in_port_t foreign_port;
1057 uuid_string_t flow_uuid_str;
1058 char message[256];
1059
1060 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1061 return;
1062 }
1063
1064 /* Do not log too much */
1065 if (tcp_log_is_rate_limited()) {
1066 return;
1067 }
1068 inp = tp->t_inpcb;
1069 so = inp->inp_socket;
1070
1071 local_port = inp->inp_lport;
1072 foreign_port = inp->inp_fport;
1073
1074 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1075 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1076
1077 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1078
1079 uuid_unparse_upper(tp->t_flow_uuid, flow_uuid_str);
1080
1081 va_list ap;
1082 va_start(ap, format);
1083 vsnprintf(message, sizeof(message), format, ap);
1084 va_end(ap);
1085
1086 #define TCP_LOG_FSW_FLOW_MESSAGE_FMT \
1087 "tcp (%s:%d) " \
1088 TCP_LOG_COMMON_PCB_FMT \
1089 "flow %s %s"
1090
1091 #define TCP_LOG_FSW_FLOW_MESSAGE_ARGS \
1092 func_name, line_no, \
1093 TCP_LOG_COMMON_PCB_ARGS, \
1094 flow_uuid_str, \
1095 message
1096
1097 os_log(OS_LOG_DEFAULT, TCP_LOG_FSW_FLOW_MESSAGE_FMT,
1098 TCP_LOG_FSW_FLOW_MESSAGE_ARGS);
1099 #undef TCP_LOG_FSW_FLOW_MESSAGE_FMT
1100 #undef TCP_LOG_FSW_FLOW_MESSAGE_ARGS
1101 }
1102 #endif /* SKYWALK */
1103
1104 void
tcp_log_state_change(struct tcpcb * tp,int new_state)1105 tcp_log_state_change(struct tcpcb *tp, int new_state)
1106 {
1107 struct inpcb *inp;
1108 struct socket *so;
1109 struct ifnet *ifp;
1110 uint32_t conntime = 0;
1111 uint32_t duration = 0;
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
1117 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1118 return;
1119 }
1120 if (new_state == tp->t_state) {
1121 return;
1122 }
1123
1124 /* Do not log too much */
1125 if (tcp_log_is_rate_limited()) {
1126 return;
1127 }
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 /*
1136 * t_connect_time is the time when the connection started on
1137 * the first SYN.
1138 *
1139 * t_starttime is when the three way handshake was completed.
1140 */
1141 if (tp->t_connect_time > 0) {
1142 duration = tcp_now - tp->t_connect_time;
1143
1144 if (tp->t_starttime > 0) {
1145 conntime = tp->t_starttime - tp->t_connect_time;
1146 }
1147 }
1148
1149 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1150 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1151
1152 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1153
1154 #define TCP_LOG_STATE_FMT \
1155 "tcp_state_changed " \
1156 TCP_LOG_COMMON_PCB_FMT
1157
1158 #define TCP_LOG_STATE_ARGS \
1159 TCP_LOG_COMMON_ARGS, \
1160 so != NULL ? so->so_gencnt : 0, \
1161 tcpstates[new_state], \
1162 inp->inp_last_proc_name, so->last_pid
1163
1164 os_log(OS_LOG_DEFAULT, TCP_LOG_STATE_FMT,
1165 TCP_LOG_STATE_ARGS);
1166 #undef TCP_LOG_STATE_FMT
1167 #undef TCP_LOG_STATE_ARGS
1168 }
1169
1170 __attribute__((noinline))
1171 void
tcp_log_output(const char * func_name,int line_no,struct tcpcb * tp,const char * format,...)1172 tcp_log_output(const char *func_name, int line_no, struct tcpcb *tp, const char *format, ...)
1173 {
1174 struct inpcb *inp;
1175 struct socket *so;
1176 struct ifnet *ifp;
1177 char laddr_buf[ADDRESS_STR_LEN];
1178 char faddr_buf[ADDRESS_STR_LEN];
1179 in_port_t local_port;
1180 in_port_t foreign_port;
1181 char message[256];
1182
1183 if (tp == NULL || tp->t_inpcb == NULL || tp->t_inpcb->inp_socket == NULL) {
1184 return;
1185 }
1186 /* Log only when fron send() or connect() */
1187 if ((tp->t_flagsext & TF_USR_OUTPUT) == 0) {
1188 return;
1189 }
1190 /* Do not log too much */
1191 if (tcp_log_is_rate_limited()) {
1192 return;
1193 }
1194 inp = tp->t_inpcb;
1195 so = inp->inp_socket;
1196
1197 local_port = inp->inp_lport;
1198 foreign_port = inp->inp_fport;
1199
1200 ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp :
1201 inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL;
1202
1203 tcp_log_inp_addresses(inp, laddr_buf, sizeof(laddr_buf), faddr_buf, sizeof(faddr_buf));
1204
1205 va_list ap;
1206 va_start(ap, format);
1207 vsnprintf(message, sizeof(message), format, ap);
1208 va_end(ap);
1209
1210 #define TCP_LOG_MESSAGE_FMT \
1211 "tcp (%s:%d) " \
1212 TCP_LOG_COMMON_PCB_FMT \
1213 "bytes in/out: %llu/%llu " \
1214 "pkts in/out: %llu/%llu " \
1215 "rxmit pkts/bytes: %u/%u" \
1216 "%s"
1217
1218 #define TCP_LOG_MESSAGE_ARGS \
1219 func_name, line_no, \
1220 TCP_LOG_COMMON_PCB_ARGS, \
1221 inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \
1222 inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \
1223 tp->t_stat.rxmitpkts, tp->t_stat.txretransmitbytes, \
1224 message
1225
1226 os_log(OS_LOG_DEFAULT, TCP_LOG_MESSAGE_FMT,
1227 TCP_LOG_MESSAGE_ARGS);
1228 #undef TCP_LOG_MESSAGE_FMT
1229 #undef TCP_LOG_MESSAGE_ARGS
1230 }
1231
1232 static int
1233 sysctl_tcp_log_port SYSCTL_HANDLER_ARGS
1234 {
1235 #pragma unused(arg1, arg2)
1236 int i, error;
1237
1238 i = tcp_log_port;
1239
1240 error = sysctl_handle_int(oidp, &i, 0, req);
1241 if (error) {
1242 return error;
1243 }
1244
1245 if (i < 0 || i > UINT16_MAX) {
1246 return EINVAL;
1247 }
1248
1249 tcp_log_port = (uint16_t)i;
1250 return 0;
1251 }
1252