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