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