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