1 | /* |
2 | * Copyright (c) 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 | |
39 | #include <netinet/inp_log.h> |
40 | #include <netinet/in_pcb.h> |
41 | |
42 | #include <netinet/udp_log.h> |
43 | #include <netinet/udp_var.h> |
44 | |
45 | SYSCTL_NODE(_net_inet_udp, OID_AUTO, log, CTLFLAG_RW | CTLFLAG_LOCKED, 0, |
46 | "UDP" ); |
47 | |
48 | #if (DEVELOPMENT || DEBUG) |
49 | #define UDP_LOG_ENABLE_DEFAULT \ |
50 | (ULEF_CONNECTION | ULEF_DST_LOCAL | ULEF_DST_GW) |
51 | #else /* (DEVELOPMENT || DEBUG) */ |
52 | #define UDP_LOG_ENABLE_DEFAULT 0 |
53 | #endif /* (DEVELOPMENT || DEBUG) */ |
54 | |
55 | uint32_t udp_log_enable_flags = UDP_LOG_ENABLE_DEFAULT; |
56 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, enable, |
57 | CTLFLAG_RW | CTLFLAG_LOCKED, &udp_log_enable_flags, 0, "" ); |
58 | |
59 | |
60 | /* |
61 | * The following is a help to describe the values of the flags |
62 | */ |
63 | #define X(name, value, description, ...) #description ":" #value " " |
64 | SYSCTL_STRING(_net_inet_udp_log, OID_AUTO, enable_usage, CTLFLAG_RD | CTLFLAG_LOCKED, |
65 | UDP_ENABLE_FLAG_LIST, 0, "" ); |
66 | #undef X |
67 | |
68 | /* |
69 | * |
70 | */ |
71 | uint32_t udp_log_local_port_included = 0; |
72 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, local_port_included, CTLFLAG_RW | CTLFLAG_LOCKED, |
73 | &udp_log_local_port_included, 0, "" ); |
74 | uint32_t udp_log_remote_port_included = 0; |
75 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, remote_port_included, CTLFLAG_RW | CTLFLAG_LOCKED, |
76 | &udp_log_remote_port_included, 0, "" ); |
77 | |
78 | uint32_t udp_log_local_port_excluded = 0; |
79 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, local_port_excluded, CTLFLAG_RW | CTLFLAG_LOCKED, |
80 | &udp_log_local_port_excluded, 0, "" ); |
81 | uint32_t udp_log_remote_port_excluded = 0; |
82 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, remote_port_excluded, CTLFLAG_RW | CTLFLAG_LOCKED, |
83 | &udp_log_remote_port_excluded, 0, "" ); |
84 | |
85 | |
86 | #define UDP_LOG_RATE_LIMIT 1000 |
87 | static unsigned int udp_log_rate_limit = UDP_LOG_RATE_LIMIT; |
88 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, rate_limit, |
89 | CTLFLAG_RW | CTLFLAG_LOCKED, &udp_log_rate_limit, 0, "" ); |
90 | |
91 | /* 1 minute by default */ |
92 | #define UDP_LOG_RATE_DURATION 60 |
93 | static unsigned int udp_log_rate_duration = UDP_LOG_RATE_DURATION; |
94 | SYSCTL_UINT(_net_inet_udp_log, OID_AUTO, rate_duration, |
95 | CTLFLAG_RW | CTLFLAG_LOCKED, &udp_log_rate_duration, 0, "" ); |
96 | |
97 | static unsigned long udp_log_rate_max = 0; |
98 | SYSCTL_ULONG(_net_inet_udp_log, OID_AUTO, rate_max, |
99 | CTLFLAG_RD | CTLFLAG_LOCKED, &udp_log_rate_max, "" ); |
100 | |
101 | static unsigned long udp_log_rate_exceeded_total = 0; |
102 | SYSCTL_ULONG(_net_inet_udp_log, OID_AUTO, rate_exceeded_total, |
103 | CTLFLAG_RD | CTLFLAG_LOCKED, &udp_log_rate_exceeded_total, "" ); |
104 | |
105 | static unsigned long udp_log_rate_current = 0; |
106 | SYSCTL_ULONG(_net_inet_udp_log, OID_AUTO, rate_current, |
107 | CTLFLAG_RD | CTLFLAG_LOCKED, &udp_log_rate_current, "" ); |
108 | |
109 | static bool udp_log_rate_exceeded_logged = false; |
110 | |
111 | static uint64_t udp_log_current_period = 0; |
112 | |
113 | #define ADDRESS_STR_LEN (MAX_IPv6_STR_LEN + 6) |
114 | |
115 | |
116 | #define UDP_LOG_COMMON_FMT \ |
117 | "[%s:%u<->%s:%u] " \ |
118 | "interface: %s " \ |
119 | "(skipped: %lu)\n" |
120 | |
121 | #define UDP_LOG_COMMON_ARGS \ |
122 | laddr_buf, ntohs(local_port), faddr_buf, ntohs(foreign_port), \ |
123 | ifp != NULL ? if_name(ifp) : "", \ |
124 | udp_log_rate_exceeded_total |
125 | |
126 | #define UDP_LOG_COMMON_PCB_FMT \ |
127 | UDP_LOG_COMMON_FMT \ |
128 | "so_gencnt: %llu " \ |
129 | "so_state: 0x%04x " \ |
130 | "process: %s:%u " |
131 | |
132 | #define UDP_LOG_COMMON_PCB_ARGS \ |
133 | UDP_LOG_COMMON_ARGS, \ |
134 | so != NULL ? so->so_gencnt : 0, \ |
135 | so != NULL ? so->so_state : 0, \ |
136 | inp->inp_last_proc_name, so->last_pid |
137 | |
138 | /* |
139 | * Returns true when above the rate limit |
140 | */ |
141 | static bool |
142 | udp_log_is_rate_limited(void) |
143 | { |
144 | uint64_t current_net_period = net_uptime(); |
145 | |
146 | /* When set to zero it means to reset to default */ |
147 | if (udp_log_rate_duration == 0) { |
148 | udp_log_rate_duration = UDP_LOG_RATE_DURATION; |
149 | } |
150 | if (udp_log_rate_limit == 0) { |
151 | udp_log_rate_duration = UDP_LOG_RATE_LIMIT; |
152 | } |
153 | |
154 | if (current_net_period > udp_log_current_period + udp_log_rate_duration) { |
155 | if (udp_log_rate_current > udp_log_rate_max) { |
156 | udp_log_rate_max = udp_log_rate_current; |
157 | } |
158 | udp_log_current_period = current_net_period; |
159 | udp_log_rate_current = 0; |
160 | udp_log_rate_exceeded_logged = false; |
161 | } |
162 | |
163 | udp_log_rate_current += 1; |
164 | |
165 | if (udp_log_rate_current > (unsigned long) udp_log_rate_limit) { |
166 | udp_log_rate_exceeded_total += 1; |
167 | return true; |
168 | } |
169 | |
170 | return false; |
171 | } |
172 | |
173 | static bool |
174 | udp_log_port_allowed(struct inpcb *inp) |
175 | { |
176 | if ((udp_log_local_port_included > 0 && udp_log_local_port_included <= IPPORT_HILASTAUTO) || |
177 | (udp_log_remote_port_included > 0 && udp_log_remote_port_included <= IPPORT_HILASTAUTO)) { |
178 | if (ntohs(inp->inp_lport) == udp_log_local_port_included || |
179 | ntohs(inp->inp_fport) == udp_log_remote_port_included) { |
180 | return true; |
181 | } else { |
182 | return false; |
183 | } |
184 | } |
185 | if ((udp_log_local_port_excluded > 0 && udp_log_local_port_excluded <= IPPORT_HILASTAUTO) || |
186 | (udp_log_remote_port_excluded > 0 && udp_log_remote_port_excluded <= IPPORT_HILASTAUTO)) { |
187 | if (ntohs(inp->inp_lport) == udp_log_local_port_excluded || |
188 | ntohs(inp->inp_fport) == udp_log_remote_port_excluded) { |
189 | return false; |
190 | } |
191 | } |
192 | return true; |
193 | } |
194 | |
195 | __attribute__((noinline)) |
196 | void |
197 | udp_log_bind(struct inpcb *inp, const char *event, int error) |
198 | { |
199 | struct socket *so; |
200 | struct ifnet *ifp; |
201 | char laddr_buf[ADDRESS_STR_LEN]; |
202 | char faddr_buf[ADDRESS_STR_LEN]; |
203 | in_port_t local_port; |
204 | in_port_t foreign_port; |
205 | |
206 | if (inp == NULL || inp->inp_socket == NULL || event == NULL) { |
207 | return; |
208 | } |
209 | |
210 | /* Do not log too much */ |
211 | if (udp_log_is_rate_limited()) { |
212 | return; |
213 | } |
214 | |
215 | if (!udp_log_port_allowed(inp)) { |
216 | return; |
217 | } |
218 | |
219 | inp->inp_flags2 &= ~INP2_LOGGED_SUMMARY; |
220 | inp->inp_flags2 |= INP2_LOGGING_ENABLED; |
221 | |
222 | so = inp->inp_socket; |
223 | |
224 | local_port = inp->inp_lport; |
225 | foreign_port = inp->inp_fport; |
226 | |
227 | ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp : |
228 | inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL; |
229 | |
230 | inp_log_addresses(inp, lbuf: laddr_buf, lbuflen: sizeof(laddr_buf), fbuf: faddr_buf, fbuflen: sizeof(faddr_buf)); |
231 | |
232 | #define UDP_LOG_BIND_FMT \ |
233 | "udp %s: " \ |
234 | UDP_LOG_COMMON_PCB_FMT \ |
235 | "bytes in/out: %llu/%llu " \ |
236 | "pkts in/out: %llu/%llu " \ |
237 | "error: %d " \ |
238 | "so_error: %d " \ |
239 | "svc/tc: %u" |
240 | |
241 | #define UDP_LOG_BIND_ARGS \ |
242 | event, \ |
243 | UDP_LOG_COMMON_PCB_ARGS, \ |
244 | inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \ |
245 | inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \ |
246 | error, \ |
247 | so->so_error, \ |
248 | (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class |
249 | |
250 | os_log(OS_LOG_DEFAULT, UDP_LOG_BIND_FMT, |
251 | UDP_LOG_BIND_ARGS); |
252 | |
253 | #undef UDP_LOG_BIND_FMT |
254 | #undef UDP_LOG_BIND_ARGS |
255 | } |
256 | |
257 | __attribute__((noinline)) |
258 | void |
259 | udp_log_connection(struct inpcb *inp, const char *event, int error) |
260 | { |
261 | struct socket *so; |
262 | struct ifnet *ifp; |
263 | char laddr_buf[ADDRESS_STR_LEN]; |
264 | char faddr_buf[ADDRESS_STR_LEN]; |
265 | in_port_t local_port; |
266 | in_port_t foreign_port; |
267 | |
268 | if (inp == NULL || inp->inp_socket == NULL || event == NULL) { |
269 | return; |
270 | } |
271 | |
272 | /* Do not log too much */ |
273 | if (udp_log_is_rate_limited()) { |
274 | return; |
275 | } |
276 | |
277 | if (!udp_log_port_allowed(inp)) { |
278 | return; |
279 | } |
280 | |
281 | /* Clear the logging flags as one may reconnect an UDP socket */ |
282 | inp->inp_flags2 &= ~INP2_LOGGED_SUMMARY; |
283 | inp->inp_flags2 |= INP2_LOGGING_ENABLED; |
284 | |
285 | so = inp->inp_socket; |
286 | |
287 | local_port = inp->inp_lport; |
288 | foreign_port = inp->inp_fport; |
289 | |
290 | ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp : |
291 | inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL; |
292 | |
293 | inp_log_addresses(inp, lbuf: laddr_buf, lbuflen: sizeof(laddr_buf), fbuf: faddr_buf, fbuflen: sizeof(faddr_buf)); |
294 | |
295 | #define UDP_LOG_CONNECT_FMT \ |
296 | "udp %s: " \ |
297 | UDP_LOG_COMMON_PCB_FMT \ |
298 | "bytes in/out: %llu/%llu " \ |
299 | "pkts in/out: %llu/%llu " \ |
300 | "error: %d " \ |
301 | "so_error: %d " \ |
302 | "svc/tc: %u " \ |
303 | "flow: 0x%x" |
304 | |
305 | #define UDP_LOG_CONNECT_ARGS \ |
306 | event, \ |
307 | UDP_LOG_COMMON_PCB_ARGS, \ |
308 | inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \ |
309 | inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \ |
310 | error, \ |
311 | so->so_error, \ |
312 | (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \ |
313 | inp->inp_flowhash |
314 | |
315 | os_log(OS_LOG_DEFAULT, UDP_LOG_CONNECT_FMT, |
316 | UDP_LOG_CONNECT_ARGS); |
317 | |
318 | #undef UDP_LOG_CONNECT_FMT |
319 | #undef UDP_LOG_CONNECT_ARGS |
320 | } |
321 | |
322 | __attribute__((noinline)) |
323 | void |
324 | udp_log_connection_summary(struct inpcb *inp) |
325 | { |
326 | struct socket *so; |
327 | struct ifnet *ifp; |
328 | clock_sec_t duration_secs = 0; |
329 | clock_usec_t duration_microsecs = 0; |
330 | clock_sec_t connection_secs = 0; |
331 | clock_usec_t connection_microsecs = 0; |
332 | char laddr_buf[ADDRESS_STR_LEN]; |
333 | char faddr_buf[ADDRESS_STR_LEN]; |
334 | in_port_t local_port; |
335 | in_port_t foreign_port; |
336 | |
337 | if (inp == NULL || inp->inp_socket == NULL) { |
338 | return; |
339 | } |
340 | if ((inp->inp_flags2 & INP2_LOGGING_ENABLED) == 0) { |
341 | return; |
342 | } |
343 | /* Make sure the summary is logged once */ |
344 | if (inp->inp_flags2 & INP2_LOGGED_SUMMARY) { |
345 | return; |
346 | } |
347 | inp->inp_flags2 |= INP2_LOGGED_SUMMARY; |
348 | inp->inp_flags2 &= ~INP2_LOGGING_ENABLED; |
349 | |
350 | /* Do not log too much */ |
351 | if (udp_log_is_rate_limited()) { |
352 | return; |
353 | } |
354 | so = inp->inp_socket; |
355 | |
356 | local_port = inp->inp_lport; |
357 | foreign_port = inp->inp_fport; |
358 | |
359 | |
360 | /* |
361 | * inp_start_timestamp is when the UDP socket was open. |
362 | * |
363 | * inp_connect_timestamp is when the connection started on |
364 | */ |
365 | uint64_t now = mach_continuous_time(); |
366 | if (inp->inp_start_timestamp > 0) { |
367 | uint64_t duration = now - inp->inp_start_timestamp; |
368 | |
369 | absolutetime_to_microtime(abstime: duration, secs: &duration_secs, microsecs: &duration_microsecs); |
370 | } |
371 | if (inp->inp_connect_timestamp > 0) { |
372 | uint64_t duration = now - inp->inp_connect_timestamp; |
373 | |
374 | absolutetime_to_microtime(abstime: duration, secs: &connection_secs, microsecs: &connection_microsecs); |
375 | } |
376 | |
377 | ifp = inp->inp_last_outifp != NULL ? inp->inp_last_outifp : |
378 | inp->inp_boundifp != NULL ? inp->inp_boundifp : NULL; |
379 | |
380 | inp_log_addresses(inp, lbuf: laddr_buf, lbuflen: sizeof(laddr_buf), fbuf: faddr_buf, fbuflen: sizeof(faddr_buf)); |
381 | |
382 | /* |
383 | * Need to use 2 log messages because the size of the summary |
384 | */ |
385 | |
386 | #define UDP_LOG_CONNECTION_SUMMARY_FMT \ |
387 | "udp_connection_summary " \ |
388 | UDP_LOG_COMMON_PCB_FMT \ |
389 | "Duration: %lu.%03d sec " \ |
390 | "Conn_Time: %lu.%03d sec " \ |
391 | "bytes in/out: %llu/%llu " \ |
392 | "pkts in/out: %llu/%llu " \ |
393 | "so_error: %d " \ |
394 | "svc/tc: %u " \ |
395 | "flow: 0x%x" |
396 | |
397 | #define UDP_LOG_CONNECTION_SUMMARY_ARGS \ |
398 | UDP_LOG_COMMON_PCB_ARGS, \ |
399 | duration_secs, duration_microsecs / 1000, \ |
400 | connection_secs, connection_microsecs / 1000, \ |
401 | inp->inp_stat->rxbytes, inp->inp_stat->txbytes, \ |
402 | inp->inp_stat->rxpackets, inp->inp_stat->txpackets, \ |
403 | so->so_error, \ |
404 | (so->so_flags1 & SOF1_TC_NET_SERV_TYPE) ? so->so_netsvctype : so->so_traffic_class, \ |
405 | inp->inp_flowhash |
406 | |
407 | os_log(OS_LOG_DEFAULT, UDP_LOG_CONNECTION_SUMMARY_FMT, |
408 | UDP_LOG_CONNECTION_SUMMARY_ARGS); |
409 | #undef UDP_LOG_CONNECTION_SUMMARY_FMT |
410 | #undef UDP_LOG_CONNECTION_SUMMARY_ARGS |
411 | |
412 | #define UDP_LOG_CONNECTION_SUMMARY_FMT \ |
413 | "udp_connection_summary " \ |
414 | UDP_LOG_COMMON_PCB_FMT \ |
415 | "flowctl: %lluus (%llux) " |
416 | |
417 | #define UDP_LOG_CONNECTION_SUMMARY_ARGS \ |
418 | UDP_LOG_COMMON_PCB_ARGS, \ |
419 | inp->inp_fadv_total_time, \ |
420 | inp->inp_fadv_cnt |
421 | |
422 | os_log(OS_LOG_DEFAULT, UDP_LOG_CONNECTION_SUMMARY_FMT, |
423 | UDP_LOG_CONNECTION_SUMMARY_ARGS); |
424 | #undef UDP_LOG_CONNECTION_SUMMARY_FMT |
425 | #undef UDP_LOG_CONNECTION_SUMMARY_ARGS |
426 | } |
427 | |