1 | /* |
2 | * Copyright (c) 2019-2023 Apple Inc. All rights reserved. |
3 | */ |
4 | |
5 | #undef offset |
6 | |
7 | #include <kern/cpu_data.h> |
8 | #include <os/base.h> |
9 | #include <os/hash.h> |
10 | #include <os/object.h> |
11 | #include <os/log.h> |
12 | #include <stdbool.h> |
13 | #include <stddef.h> |
14 | #include <stdint.h> |
15 | |
16 | #include <vm/vm_kern.h> |
17 | #include <mach/vm_statistics.h> |
18 | #include <kern/debug.h> |
19 | #include <libkern/libkern.h> |
20 | #include <libkern/kernel_mach_header.h> |
21 | #include <pexpert/pexpert.h> |
22 | #include <uuid/uuid.h> |
23 | #include <sys/msgbuf.h> |
24 | |
25 | #include <mach/mach_time.h> |
26 | #include <kern/thread.h> |
27 | #include <kern/simple_lock.h> |
28 | #include <kern/kalloc.h> |
29 | #include <kern/clock.h> |
30 | #include <kern/assert.h> |
31 | #include <kern/smr_hash.h> |
32 | #include <kern/startup.h> |
33 | #include <kern/task.h> |
34 | |
35 | #include <firehose/firehose_types_private.h> |
36 | #include <firehose/tracepoint_private.h> |
37 | #include <firehose/chunk_private.h> |
38 | #include <os/firehose_buffer_private.h> |
39 | #include <os/firehose.h> |
40 | #include <os/log_private.h> |
41 | |
42 | #include "log_encode.h" |
43 | #include "log_internal.h" |
44 | #include "log_mem.h" |
45 | #include "log_queue.h" |
46 | #include "trace_internal.h" |
47 | |
48 | #define OS_LOGMEM_BUF_ORDER 14 |
49 | #define OS_LOGMEM_MIN_LOG_ORDER 9 |
50 | #define OS_LOGMEM_MAX_LOG_ORDER (OS_LOG_MAX_SIZE_ORDER) |
51 | |
52 | #define OS_LOG_SUBSYSTEM_MAX_CNT 1024 |
53 | #define OS_LOG_SUBSYSTEM_NONE 0xffff |
54 | #define OS_LOG_SUBSYSTEM_BASE 0x0001 // OS_LOG_DEFAULT takes 0 by definition |
55 | #define OS_LOG_SUBSYSTEM_LAST (OS_LOG_SUBSYSTEM_BASE + OS_LOG_SUBSYSTEM_MAX_CNT) |
56 | #define OS_LOG_SUBSYSTEM_NAME_MAX_LEN 128 |
57 | |
58 | /* |
59 | * OSLog subsystem type. The struct layout matches its libtrace counterpart |
60 | * and also matches what libtrace (logd) expects from subsystem registration |
61 | * metadata payload. |
62 | */ |
63 | struct os_log_subsystem_s { |
64 | uint16_t ols_id; |
65 | union { |
66 | struct { |
67 | uint8_t ols_sub_size; |
68 | uint8_t ols_cat_size; |
69 | }; |
70 | uint16_t ols_sizes; |
71 | }; |
72 | char ols_name[2 * OS_LOG_SUBSYSTEM_NAME_MAX_LEN]; |
73 | }; |
74 | |
75 | struct os_log_s { |
76 | struct os_log_subsystem_s ol_subsystem; |
77 | struct smrq_slink ol_hash_link; |
78 | }; |
79 | |
80 | struct os_log_s _os_log_default; |
81 | struct os_log_s _os_log_replay; |
82 | |
83 | /* Counters for persistence mode */ |
84 | SCALABLE_COUNTER_DEFINE(oslog_p_total_msgcount); |
85 | SCALABLE_COUNTER_DEFINE(oslog_p_metadata_saved_msgcount); |
86 | SCALABLE_COUNTER_DEFINE(oslog_p_metadata_dropped_msgcount); |
87 | SCALABLE_COUNTER_DEFINE(oslog_p_signpost_saved_msgcount); |
88 | SCALABLE_COUNTER_DEFINE(oslog_p_signpost_dropped_msgcount); |
89 | SCALABLE_COUNTER_DEFINE(oslog_p_error_count); |
90 | SCALABLE_COUNTER_DEFINE(oslog_p_saved_msgcount); |
91 | SCALABLE_COUNTER_DEFINE(oslog_p_dropped_msgcount); |
92 | SCALABLE_COUNTER_DEFINE(oslog_p_boot_dropped_msgcount); |
93 | SCALABLE_COUNTER_DEFINE(oslog_p_coprocessor_total_msgcount); |
94 | SCALABLE_COUNTER_DEFINE(oslog_p_coprocessor_dropped_msgcount); |
95 | SCALABLE_COUNTER_DEFINE(oslog_p_unresolved_kc_msgcount); |
96 | |
97 | /* Counters for msgbuf logging */ |
98 | SCALABLE_COUNTER_DEFINE(oslog_msgbuf_msgcount) |
99 | SCALABLE_COUNTER_DEFINE(oslog_msgbuf_dropped_msgcount) |
100 | |
101 | /* Log subsystem counters */ |
102 | SCALABLE_COUNTER_DEFINE(oslog_subsystem_count); |
103 | SCALABLE_COUNTER_DEFINE(oslog_subsystem_found); |
104 | SCALABLE_COUNTER_DEFINE(oslog_subsystem_dropped); |
105 | |
106 | LCK_GRP_DECLARE(oslog_cache_lock_grp, "oslog_cache_lock_grp" ); |
107 | LCK_TICKET_DECLARE(oslog_cache_lock, &oslog_cache_lock_grp); |
108 | |
109 | static bool oslog_boot_done = false; |
110 | static SECURITY_READ_ONLY_LATE(bool) oslog_disabled = false; |
111 | |
112 | static uint16_t os_log_subsystem_id = OS_LOG_SUBSYSTEM_BASE; |
113 | |
114 | static struct logmem_s os_log_mem; |
115 | static struct smr_hash os_log_cache; |
116 | |
117 | static struct firehose_chunk_s firehose_boot_chunk = { |
118 | .fc_pos = { |
119 | .fcp_next_entry_offs = offsetof(struct firehose_chunk_s, fc_data), |
120 | .fcp_private_offs = FIREHOSE_CHUNK_SIZE, |
121 | .fcp_refcnt = 1, // Indicate that there is a writer to this chunk |
122 | .fcp_stream = firehose_stream_persist, |
123 | .fcp_flag_io = 1, // Lets assume this is coming from the io bank |
124 | }, |
125 | }; |
126 | |
127 | bool os_log_disabled(void); |
128 | |
129 | extern vm_offset_t kernel_firehose_addr; |
130 | extern bool bsd_log_lock(bool); |
131 | extern void bsd_log_unlock(void); |
132 | extern void logwakeup(void); |
133 | extern void oslog_stream(bool, firehose_tracepoint_id_u, uint64_t, const void *, size_t); |
134 | extern void *OSKextKextForAddress(const void *); |
135 | |
136 | static bool |
137 | os_log_safe(void) |
138 | { |
139 | return oslog_is_safe() || startup_phase < STARTUP_SUB_EARLY_BOOT; |
140 | } |
141 | |
142 | static bool |
143 | os_log_turned_off(void) |
144 | { |
145 | return oslog_disabled || (atm_get_diagnostic_config() & ATM_TRACE_OFF); |
146 | } |
147 | |
148 | bool |
149 | os_log_info_enabled(os_log_t log __unused) |
150 | { |
151 | return !os_log_turned_off(); |
152 | } |
153 | |
154 | bool |
155 | os_log_debug_enabled(os_log_t log __unused) |
156 | { |
157 | return !os_log_turned_off(); |
158 | } |
159 | |
160 | bool |
161 | os_log_disabled(void) |
162 | { |
163 | return oslog_disabled; |
164 | } |
165 | |
166 | static inline size_t |
167 | log_payload_priv_data_size(const log_payload_s *lp) |
168 | { |
169 | assert3u(lp->lp_pub_data_size, <=, lp->lp_data_size); |
170 | return lp->lp_data_size - lp->lp_pub_data_size; |
171 | } |
172 | |
173 | static inline const uint8_t * |
174 | log_payload_priv_data(const log_payload_s *lp, const uint8_t *lp_data) |
175 | { |
176 | if (log_payload_priv_data_size(lp) == 0) { |
177 | return NULL; |
178 | } |
179 | return &lp_data[lp->lp_pub_data_size]; |
180 | } |
181 | |
182 | static void |
183 | log_payload_init(log_payload_t lp, firehose_stream_t stream, firehose_tracepoint_id_u ftid, |
184 | uint64_t timestamp, size_t data_size, size_t pub_data_size) |
185 | { |
186 | assert3u(pub_data_size, <=, data_size); |
187 | assert3u(data_size, <, UINT16_MAX); |
188 | |
189 | lp->lp_stream = stream; |
190 | lp->lp_ftid = ftid; |
191 | lp->lp_timestamp = timestamp; |
192 | lp->lp_pub_data_size = (uint16_t)pub_data_size; |
193 | lp->lp_data_size = (uint16_t)data_size; |
194 | } |
195 | |
196 | static firehose_stream_t |
197 | firehose_stream(os_log_type_t type) |
198 | { |
199 | return (type == OS_LOG_TYPE_INFO || type == OS_LOG_TYPE_DEBUG) ? |
200 | firehose_stream_memory : firehose_stream_persist; |
201 | } |
202 | |
203 | static firehose_tracepoint_id_t |
204 | firehose_ftid(os_log_type_t type, const char *fmt, firehose_tracepoint_flags_t flags, |
205 | void *dso, void *addr, bool driverKit) |
206 | { |
207 | uint32_t off; |
208 | |
209 | if (driverKit) { |
210 | /* |
211 | * Set FIREHOSE_TRACEPOINT_PC_DYNAMIC_BIT so logd will not try |
212 | * to find the format string in the executable text. |
213 | */ |
214 | off = (uint32_t)((uintptr_t)addr | FIREHOSE_TRACEPOINT_PC_DYNAMIC_BIT); |
215 | } else { |
216 | off = _os_trace_offset(dso, addr: fmt, flags: (_firehose_tracepoint_flags_activity_t)flags); |
217 | } |
218 | |
219 | return FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_log, type, flags, off); |
220 | } |
221 | |
222 | static firehose_tracepoint_flags_t |
223 | firehose_ftid_flags(const void *dso, bool driverKit) |
224 | { |
225 | kc_format_t kcformat = KCFormatUnknown; |
226 | __assert_only bool result = PE_get_primary_kc_format(type: &kcformat); |
227 | assert(result); |
228 | |
229 | if (kcformat == KCFormatStatic || kcformat == KCFormatKCGEN) { |
230 | return _firehose_tracepoint_flags_pc_style_shared_cache; |
231 | } |
232 | |
233 | /* |
234 | * driverKit will have the dso set as MH_EXECUTE (it is logging from a |
235 | * syscall in the kernel) but needs logd to parse the address as an |
236 | * absolute pc. |
237 | */ |
238 | const kernel_mach_header_t *mh = dso; |
239 | if (mh->filetype == MH_EXECUTE && !driverKit) { |
240 | return _firehose_tracepoint_flags_pc_style_main_exe; |
241 | } |
242 | |
243 | return _firehose_tracepoint_flags_pc_style_absolute; |
244 | } |
245 | |
246 | static void * |
247 | resolve_dso(const char *fmt, void *dso, void *addr, bool driverKit) |
248 | { |
249 | kc_format_t kcformat = KCFormatUnknown; |
250 | |
251 | if (!addr || !PE_get_primary_kc_format(type: &kcformat)) { |
252 | return NULL; |
253 | } |
254 | |
255 | switch (kcformat) { |
256 | case KCFormatStatic: |
257 | case KCFormatKCGEN: |
258 | dso = PE_get_kc_baseaddress(type: KCKindPrimary); |
259 | break; |
260 | case KCFormatDynamic: |
261 | case KCFormatFileset: |
262 | if (!dso && (dso = (void *)OSKextKextForAddress(fmt)) == NULL) { |
263 | return NULL; |
264 | } |
265 | if (!_os_trace_addr_in_text_segment(dso, addr: fmt)) { |
266 | return NULL; |
267 | } |
268 | if (!driverKit && (dso != (void *)OSKextKextForAddress(addr))) { |
269 | return NULL; |
270 | } |
271 | break; |
272 | default: |
273 | panic("unknown KC format type" ); |
274 | } |
275 | |
276 | return dso; |
277 | } |
278 | |
279 | static inline uintptr_t |
280 | resolve_location(firehose_tracepoint_flags_t flags, uintptr_t dso, uintptr_t addr, |
281 | bool driverKit, size_t *loc_size) |
282 | { |
283 | switch (flags & _firehose_tracepoint_flags_pc_style_mask) { |
284 | case _firehose_tracepoint_flags_pc_style_shared_cache: |
285 | case _firehose_tracepoint_flags_pc_style_main_exe: |
286 | *loc_size = sizeof(uint32_t); |
287 | return addr - dso; |
288 | case _firehose_tracepoint_flags_pc_style_absolute: |
289 | *loc_size = sizeof(uintptr_t); |
290 | return driverKit ? addr : VM_KERNEL_UNSLIDE(addr); |
291 | default: |
292 | panic("Unknown firehose tracepoint flags %x" , flags); |
293 | } |
294 | } |
295 | |
296 | __startup_func |
297 | static void |
298 | oslog_init(void) |
299 | { |
300 | /* |
301 | * Disable kernel logging if ATM_TRACE_DISABLE set. ATM_TRACE_DISABLE |
302 | * bit is not supposed to change during a system run but nothing really |
303 | * prevents userspace from unintentionally doing so => we stash initial |
304 | * value in a dedicated variable for a later reference, just in case. |
305 | */ |
306 | oslog_disabled = atm_get_diagnostic_config() & ATM_TRACE_DISABLE; |
307 | |
308 | if (!oslog_disabled) { |
309 | smr_hash_init(smrh: &os_log_cache, OS_LOG_SUBSYSTEM_MAX_CNT / 4); |
310 | } |
311 | } |
312 | STARTUP(OSLOG, STARTUP_RANK_FIRST, oslog_init); |
313 | |
314 | __startup_func |
315 | static void |
316 | oslog_init_logmem(void) |
317 | { |
318 | if (os_log_disabled()) { |
319 | printf("Long logs support disabled: Logging disabled by ATM\n" ); |
320 | return; |
321 | } |
322 | |
323 | const size_t logmem_size = logmem_required_size(OS_LOGMEM_BUF_ORDER, OS_LOGMEM_MIN_LOG_ORDER); |
324 | vm_offset_t addr; |
325 | |
326 | if (kmem_alloc(map: kernel_map, addrp: &addr, size: logmem_size + ptoa(2), |
327 | flags: KMA_KOBJECT | KMA_PERMANENT | KMA_ZERO | KMA_GUARD_FIRST | KMA_GUARD_LAST, |
328 | VM_KERN_MEMORY_LOG) == KERN_SUCCESS) { |
329 | logmem_init(&os_log_mem, (void *)(addr + PAGE_SIZE), logmem_size, |
330 | OS_LOGMEM_BUF_ORDER, OS_LOGMEM_MIN_LOG_ORDER, OS_LOGMEM_MAX_LOG_ORDER); |
331 | printf("Long logs support configured: size: %u\n" , os_log_mem.lm_cnt_free); |
332 | } else { |
333 | printf("Long logs support disabled: Not enough memory\n" ); |
334 | } |
335 | } |
336 | STARTUP(OSLOG, STARTUP_RANK_SECOND, oslog_init_logmem); |
337 | |
338 | bool |
339 | os_log_encoded_metadata(firehose_tracepoint_id_u ftid, uint64_t ts, const void *msg, |
340 | size_t msg_size) |
341 | { |
342 | assert(ftid.ftid._namespace == firehose_tracepoint_namespace_metadata); |
343 | counter_inc(&oslog_p_total_msgcount); |
344 | |
345 | if (!os_log_safe() || os_log_disabled()) { |
346 | counter_inc(&oslog_p_metadata_dropped_msgcount); |
347 | return false; |
348 | } |
349 | |
350 | log_payload_s log; |
351 | log_payload_init(lp: &log, stream: firehose_stream_metadata, ftid, timestamp: ts, data_size: msg_size, pub_data_size: msg_size); |
352 | |
353 | if (log_queue_log(&log, msg, true)) { |
354 | return true; |
355 | } |
356 | |
357 | counter_inc(&oslog_p_metadata_dropped_msgcount); |
358 | return false; |
359 | } |
360 | |
361 | bool |
362 | os_log_encoded_log(firehose_tracepoint_id_u ftid, uint64_t ts, const void *msg, |
363 | size_t msg_size, size_t pub_data_size) |
364 | { |
365 | assert(ftid.ftid._namespace == firehose_tracepoint_namespace_log); |
366 | counter_inc(&oslog_p_total_msgcount); |
367 | |
368 | if (!os_log_safe() || os_log_disabled()) { |
369 | counter_inc(&oslog_p_dropped_msgcount); |
370 | return false; |
371 | } |
372 | |
373 | firehose_stream_t stream = firehose_stream(type: ftid.ftid._type); |
374 | |
375 | log_payload_s log; |
376 | log_payload_init(lp: &log, stream, ftid, timestamp: ts, data_size: msg_size, pub_data_size); |
377 | |
378 | if (log_queue_log(&log, msg, true)) { |
379 | return true; |
380 | } |
381 | |
382 | counter_inc(&oslog_p_dropped_msgcount); |
383 | return false; |
384 | } |
385 | |
386 | bool |
387 | os_log_encoded_signpost(firehose_tracepoint_id_u ftid, uint64_t ts, const void *msg, |
388 | size_t msg_size, size_t pub_data_size) |
389 | { |
390 | assert(ftid.ftid._namespace == firehose_tracepoint_namespace_signpost); |
391 | counter_inc(&oslog_p_total_msgcount); |
392 | |
393 | if (!os_log_safe() || os_log_disabled()) { |
394 | counter_inc(&oslog_p_signpost_dropped_msgcount); |
395 | return false; |
396 | } |
397 | |
398 | log_payload_s log; |
399 | log_payload_init(lp: &log, stream: firehose_stream_signpost, ftid, timestamp: ts, data_size: msg_size, pub_data_size); |
400 | |
401 | if (log_queue_log(&log, msg, true)) { |
402 | return true; |
403 | } |
404 | |
405 | counter_inc(&oslog_p_signpost_dropped_msgcount); |
406 | return false; |
407 | } |
408 | |
409 | static inline size_t |
410 | os_log_subsystem_name_size(const char *name) |
411 | { |
412 | return MIN(strlen(name) + 1, OS_LOG_SUBSYSTEM_NAME_MAX_LEN); |
413 | } |
414 | |
415 | bool |
416 | os_log_subsystem_id_valid(uint16_t sid) |
417 | { |
418 | return sid >= OS_LOG_SUBSYSTEM_BASE && sid <= os_log_subsystem_id; |
419 | } |
420 | |
421 | static inline size_t |
422 | os_log_subsystem_id_length(const struct os_log_subsystem_s *sub) |
423 | { |
424 | return sub->ols_sub_size + sub->ols_cat_size; |
425 | } |
426 | |
427 | static inline size_t |
428 | os_log_subsystem_size(const struct os_log_subsystem_s *tbs) |
429 | { |
430 | assert(tbs->ols_sub_size <= OS_LOG_SUBSYSTEM_NAME_MAX_LEN); |
431 | assert(tbs->ols_cat_size <= OS_LOG_SUBSYSTEM_NAME_MAX_LEN); |
432 | return sizeof(*tbs) - sizeof(tbs->ols_name) + os_log_subsystem_id_length(sub: tbs); |
433 | } |
434 | |
435 | static void |
436 | os_log_subsystem_init(struct os_log_subsystem_s *ols, uint16_t sid, const char *sub, const char *cat) |
437 | { |
438 | ols->ols_sub_size = os_log_subsystem_name_size(name: sub); |
439 | ols->ols_cat_size = os_log_subsystem_name_size(name: cat); |
440 | strlcpy(dst: &ols->ols_name[0], src: sub, OS_LOG_SUBSYSTEM_NAME_MAX_LEN); |
441 | strlcpy(dst: &ols->ols_name[ols->ols_sub_size], src: cat, OS_LOG_SUBSYSTEM_NAME_MAX_LEN); |
442 | ols->ols_id = sid; |
443 | } |
444 | |
445 | static void |
446 | os_log_subsystem_register(const struct os_log_subsystem_s *ols, uint64_t stamp) |
447 | { |
448 | assert(os_log_subsystem_id_valid(ols->ols_id)); |
449 | |
450 | firehose_tracepoint_id_u trace_id; |
451 | trace_id.ftid_value = FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_metadata, |
452 | _firehose_tracepoint_type_metadata_subsystem, 0, ols->ols_id); |
453 | |
454 | os_log_encoded_metadata(ftid: trace_id, ts: stamp, msg: ols, msg_size: os_log_subsystem_size(tbs: ols)); |
455 | } |
456 | |
457 | #if DEVELOPMENT || DEBUG |
458 | static bool |
459 | os_log_valid(const struct os_log_s *log) |
460 | { |
461 | return os_log_subsystem_id_valid(log->ol_subsystem.ols_id); |
462 | } |
463 | #endif // DEVELOPMENT || DEBUG |
464 | |
465 | static smrh_key_t |
466 | os_log_key(const struct os_log_subsystem_s *sub) |
467 | { |
468 | return (smrh_key_t) { |
469 | .smrk_opaque = sub->ols_name, |
470 | .smrk_len = os_log_subsystem_id_length(sub) |
471 | }; |
472 | } |
473 | |
474 | static uint32_t |
475 | os_log_key_hash(smrh_key_t key, uint32_t seed) |
476 | { |
477 | return smrh_key_hash_mem(key, seed); |
478 | } |
479 | |
480 | static bool |
481 | os_log_key_equ(smrh_key_t k1, smrh_key_t k2) |
482 | { |
483 | return k1.smrk_len == k2.smrk_len ? smrh_key_equ_mem(k1, k2) : false; |
484 | } |
485 | |
486 | static uint32_t |
487 | os_log_hash(const struct smrq_slink *link, uint32_t seed) |
488 | { |
489 | const os_log_t log = __container_of(link, struct os_log_s, ol_hash_link); |
490 | return os_log_key_hash(key: os_log_key(sub: &log->ol_subsystem), seed); |
491 | } |
492 | |
493 | static bool |
494 | os_log_equ(const struct smrq_slink *link, smrh_key_t key) |
495 | { |
496 | const os_log_t h = __container_of(link, struct os_log_s, ol_hash_link); |
497 | return os_log_key_equ(k1: os_log_key(sub: &h->ol_subsystem), k2: key); |
498 | } |
499 | |
500 | static bool |
501 | oslog_try_get(void *oslog __unused) |
502 | { |
503 | return true; |
504 | } |
505 | |
506 | SMRH_TRAITS_DEFINE(os_log_cache_traits, struct os_log_s, ol_hash_link, |
507 | .domain = &smr_oslog, |
508 | .key_hash = os_log_key_hash, |
509 | .key_equ = os_log_key_equ, |
510 | .obj_hash = os_log_hash, |
511 | .obj_equ = os_log_equ, |
512 | .obj_try_get = oslog_try_get |
513 | ); |
514 | |
515 | static os_log_t |
516 | os_log_cache_find_by_sub(const struct os_log_subsystem_s *sub) |
517 | { |
518 | os_log_t log = smr_hash_get(&os_log_cache, os_log_key(sub), &os_log_cache_traits); |
519 | assert(!log || os_log_valid(log)); |
520 | return log; |
521 | } |
522 | |
523 | static os_log_t |
524 | os_log_cache_insert(os_log_t log) |
525 | { |
526 | assert(os_log_subsystem_id_valid(log->ol_subsystem.ols_id)); |
527 | |
528 | os_log_t found = smr_hash_serialized_get_or_insert(&os_log_cache, |
529 | os_log_key(&log->ol_subsystem), &log->ol_hash_link, |
530 | &os_log_cache_traits); |
531 | assert(!found || os_log_valid(found)); |
532 | return found; |
533 | } |
534 | |
535 | static os_log_t |
536 | os_log_allocate(const struct os_log_subsystem_s *subsystem) |
537 | { |
538 | os_log_t new = kalloc_type(struct os_log_s, Z_WAITOK_ZERO); |
539 | if (new) { |
540 | new->ol_subsystem = *subsystem; |
541 | } |
542 | return new; |
543 | } |
544 | |
545 | static uint16_t |
546 | os_log_subsystem_id_next(void) |
547 | { |
548 | assert(os_log_subsystem_id_valid(os_log_subsystem_id)); |
549 | |
550 | if (__improbable(os_log_subsystem_id == OS_LOG_SUBSYSTEM_LAST)) { |
551 | return OS_LOG_SUBSYSTEM_NONE; |
552 | } |
553 | return os_log_subsystem_id++; |
554 | } |
555 | |
556 | static void |
557 | os_log_subsystem_id_revert(uint16_t __assert_only sid) |
558 | { |
559 | assert(os_log_subsystem_id_valid(os_log_subsystem_id)); |
560 | assert3u(os_log_subsystem_id, ==, sid + 1); |
561 | os_log_subsystem_id--; |
562 | } |
563 | |
564 | static os_log_t |
565 | os_log_create_impl(const char *subsystem, const char *category, uint64_t stamp) |
566 | { |
567 | if (os_log_disabled()) { |
568 | return OS_LOG_DISABLED; |
569 | } |
570 | |
571 | struct os_log_subsystem_s new_sub; |
572 | os_log_subsystem_init(ols: &new_sub, OS_LOG_SUBSYSTEM_NONE, sub: subsystem, cat: category); |
573 | |
574 | os_log_t log = os_log_cache_find_by_sub(sub: &new_sub); |
575 | if (log) { |
576 | counter_inc(&oslog_subsystem_found); |
577 | return log; |
578 | } |
579 | |
580 | if (!(log = os_log_allocate(subsystem: &new_sub))) { |
581 | counter_inc(&oslog_subsystem_dropped); |
582 | return OS_LOG_DEFAULT; |
583 | } |
584 | |
585 | lck_ticket_lock(tlock: &oslog_cache_lock, grp: &oslog_cache_lock_grp); |
586 | |
587 | log->ol_subsystem.ols_id = os_log_subsystem_id_next(); |
588 | if (__improbable(log->ol_subsystem.ols_id == OS_LOG_SUBSYSTEM_NONE)) { |
589 | lck_ticket_unlock(tlock: &oslog_cache_lock); |
590 | kfree_type(struct os_log_s, log); |
591 | counter_inc(&oslog_subsystem_dropped); |
592 | return OS_LOG_DEFAULT; |
593 | } |
594 | |
595 | os_log_t found = os_log_cache_insert(log); |
596 | if (__improbable(found)) { |
597 | os_log_subsystem_id_revert(sid: log->ol_subsystem.ols_id); |
598 | lck_ticket_unlock(tlock: &oslog_cache_lock); |
599 | kfree_type(struct os_log_s, log); |
600 | counter_inc(&oslog_subsystem_found); |
601 | return found; |
602 | } |
603 | |
604 | lck_ticket_unlock(tlock: &oslog_cache_lock); |
605 | |
606 | os_log_subsystem_register(ols: &log->ol_subsystem, stamp); |
607 | counter_inc(&oslog_subsystem_count); |
608 | |
609 | return log; |
610 | } |
611 | |
612 | os_log_t |
613 | os_log_create(const char *subsystem, const char *category) |
614 | { |
615 | uint64_t stamp = firehose_tracepoint_time(flags: firehose_activity_flags_default); |
616 | return os_log_create_impl(subsystem, category, stamp); |
617 | } |
618 | |
619 | static void |
620 | _os_log_to_msgbuf_internal(const char *format, va_list args, uint64_t timestamp, |
621 | bool safe, bool logging, bool addcr) |
622 | { |
623 | /* |
624 | * The following threshold was determined empirically as the point where |
625 | * it would be more advantageous to be able to fit in more log lines than |
626 | * to know exactly when a log line was printed out. We don't want to use up |
627 | * a large percentage of the log buffer on timestamps in a memory-constricted |
628 | * environment. |
629 | */ |
630 | const int MSGBUF_TIMESTAMP_THRESHOLD = 4096; |
631 | static int msgbufreplay = -1; |
632 | static bool newlogline = true; |
633 | va_list args_copy; |
634 | |
635 | if (!bsd_log_lock(safe)) { |
636 | counter_inc(&oslog_msgbuf_dropped_msgcount); |
637 | return; |
638 | } |
639 | |
640 | if (!safe) { |
641 | if (-1 == msgbufreplay) { |
642 | msgbufreplay = msgbufp->msg_bufx; |
643 | } |
644 | } else if (logging && (-1 != msgbufreplay)) { |
645 | uint32_t i; |
646 | uint32_t localbuff_size; |
647 | int newl, position; |
648 | char *localbuff, *p, *s, *next, ch; |
649 | |
650 | position = msgbufreplay; |
651 | msgbufreplay = -1; |
652 | localbuff_size = (msgbufp->msg_size + 2); /* + '\n' + '\0' */ |
653 | /* Size for non-blocking */ |
654 | if (localbuff_size > 4096) { |
655 | localbuff_size = 4096; |
656 | } |
657 | bsd_log_unlock(); |
658 | /* Allocate a temporary non-circular buffer */ |
659 | localbuff = kalloc_data(localbuff_size, Z_NOWAIT); |
660 | if (localbuff != NULL) { |
661 | /* in between here, the log could become bigger, but that's fine */ |
662 | bsd_log_lock(true); |
663 | /* |
664 | * The message buffer is circular; start at the replay pointer, and |
665 | * make one loop up to write pointer - 1. |
666 | */ |
667 | p = msgbufp->msg_bufc + position; |
668 | for (i = newl = 0; p != msgbufp->msg_bufc + msgbufp->msg_bufx - 1; ++p) { |
669 | if (p >= msgbufp->msg_bufc + msgbufp->msg_size) { |
670 | p = msgbufp->msg_bufc; |
671 | } |
672 | ch = *p; |
673 | if (ch == '\0') { |
674 | continue; |
675 | } |
676 | newl = (ch == '\n'); |
677 | localbuff[i++] = ch; |
678 | if (i >= (localbuff_size - 2)) { |
679 | break; |
680 | } |
681 | } |
682 | bsd_log_unlock(); |
683 | |
684 | if (!newl) { |
685 | localbuff[i++] = '\n'; |
686 | } |
687 | localbuff[i++] = 0; |
688 | |
689 | s = localbuff; |
690 | while ((next = strchr(s, c: '\n'))) { |
691 | next++; |
692 | ch = next[0]; |
693 | next[0] = 0; |
694 | os_log(&_os_log_replay, "%s" , s); |
695 | next[0] = ch; |
696 | s = next; |
697 | } |
698 | kfree_data(localbuff, localbuff_size); |
699 | } |
700 | bsd_log_lock(true); |
701 | } |
702 | |
703 | /* Do not prepend timestamps when we are memory-constricted */ |
704 | if (newlogline && (msgbufp->msg_size > MSGBUF_TIMESTAMP_THRESHOLD)) { |
705 | clock_sec_t secs; |
706 | clock_usec_t microsecs; |
707 | absolutetime_to_microtime(abstime: timestamp, secs: &secs, microsecs: µsecs); |
708 | printf_log_locked(FALSE, "[%5lu.%06u]: " , (unsigned long)secs, microsecs); |
709 | } |
710 | |
711 | #pragma clang diagnostic push |
712 | #pragma clang diagnostic ignored "-Wformat-nonliteral" |
713 | va_copy(args_copy, args); |
714 | newlogline = vprintf_log_locked(format, args_copy, driverkit: addcr); |
715 | va_end(args_copy); |
716 | #pragma clang diagnostic pop |
717 | |
718 | bsd_log_unlock(); |
719 | logwakeup(); |
720 | counter_inc(&oslog_msgbuf_msgcount); |
721 | } |
722 | |
723 | static void |
724 | _os_log_to_log_internal(uint16_t sid, os_log_type_t type, const char *fmt, va_list args, |
725 | uint64_t ts, void *addr, void *dso, bool driverKit) |
726 | { |
727 | dso = resolve_dso(fmt, dso, addr, driverKit); |
728 | if (__improbable(!dso)) { |
729 | counter_inc(&oslog_p_unresolved_kc_msgcount); |
730 | return; |
731 | } |
732 | |
733 | firehose_tracepoint_flags_t flags = firehose_ftid_flags(dso, driverKit); |
734 | if (sid != 0) { |
735 | flags |= _firehose_tracepoint_flags_log_has_subsystem; |
736 | } |
737 | |
738 | size_t loc_sz = 0; |
739 | uintptr_t loc = resolve_location(flags, dso: (uintptr_t)dso, addr: (uintptr_t)addr, |
740 | driverKit, loc_size: &loc_sz); |
741 | |
742 | firehose_tracepoint_id_u ftid = { |
743 | .ftid_value = firehose_ftid(type, fmt, flags, dso, addr, driverKit) |
744 | }; |
745 | |
746 | __attribute__((uninitialized, aligned(8))) |
747 | uint8_t buffer[OS_LOG_BUFFER_MAX_SIZE]; |
748 | struct os_log_context_s ctx; |
749 | |
750 | os_log_context_init(&ctx, &os_log_mem, buffer, sizeof(buffer)); |
751 | |
752 | if (!os_log_context_encode(&ctx, fmt, args, loc, loc_sz, sid)) { |
753 | counter_inc(&oslog_p_error_count); |
754 | os_log_context_free(&ctx); |
755 | return; |
756 | } |
757 | |
758 | log_payload_s log; |
759 | log_payload_init(lp: &log, stream: firehose_stream(type), ftid, timestamp: ts, data_size: ctx.ctx_content_sz, pub_data_size: ctx.ctx_content_sz); |
760 | |
761 | if (!log_queue_log(&log, ctx.ctx_buffer, true)) { |
762 | counter_inc(&oslog_p_dropped_msgcount); |
763 | } |
764 | |
765 | os_log_context_free(&ctx); |
766 | } |
767 | |
768 | static void |
769 | _os_log_with_args_internal(os_log_t oslog, os_log_type_t type, const char *fmt, |
770 | va_list args, uint64_t ts, void *addr, void *dso, bool driverKit, bool addcr) |
771 | { |
772 | counter_inc(&oslog_p_total_msgcount); |
773 | |
774 | if (oslog == OS_LOG_DISABLED) { |
775 | counter_inc(&oslog_p_dropped_msgcount); |
776 | return; |
777 | } |
778 | |
779 | if (__improbable(fmt[0] == '\0')) { |
780 | counter_inc(&oslog_p_error_count); |
781 | return; |
782 | } |
783 | |
784 | /* early boot can log to dmesg for later replay (27307943) */ |
785 | bool safe = os_log_safe(); |
786 | bool logging = !os_log_turned_off(); |
787 | |
788 | if (oslog != &_os_log_replay) { |
789 | _os_log_to_msgbuf_internal(format: fmt, args, timestamp: ts, safe, logging, addcr); |
790 | } |
791 | |
792 | if (safe && logging) { |
793 | const uint16_t sid = oslog->ol_subsystem.ols_id; |
794 | _os_log_to_log_internal(sid, type, fmt, args, ts, addr, dso, driverKit); |
795 | } |
796 | } |
797 | |
798 | __attribute__((noinline, not_tail_called)) void |
799 | _os_log_internal(void *dso, os_log_t log, uint8_t type, const char *fmt, ...) |
800 | { |
801 | uint64_t ts = firehose_tracepoint_time(flags: firehose_activity_flags_default); |
802 | void *addr = __builtin_return_address(0); |
803 | va_list args; |
804 | |
805 | va_start(args, fmt); |
806 | _os_log_with_args_internal(oslog: log, type, fmt, args, ts, addr, dso, FALSE, FALSE); |
807 | va_end(args); |
808 | } |
809 | |
810 | __attribute__((noinline, not_tail_called)) void |
811 | _os_log_at_time(void *dso, os_log_t log, uint8_t type, uint64_t ts, const char *fmt, ...) |
812 | { |
813 | void *addr = __builtin_return_address(0); |
814 | va_list args; |
815 | |
816 | va_start(args, fmt); |
817 | _os_log_with_args_internal(oslog: log, type, fmt, args, ts, addr, dso, FALSE, FALSE); |
818 | va_end(args); |
819 | } |
820 | |
821 | __attribute__((noinline, not_tail_called)) int |
822 | _os_log_internal_driverKit(void *dso, os_log_t log, uint8_t type, const char *fmt, ...) |
823 | { |
824 | uint64_t ts = firehose_tracepoint_time(flags: firehose_activity_flags_default); |
825 | void *addr = __builtin_return_address(0); |
826 | bool driverKitLog = FALSE; |
827 | va_list args; |
828 | |
829 | /* |
830 | * We want to be able to identify dexts from the logs. |
831 | * |
832 | * Usually the addr is used to understand if the log line |
833 | * was generated by a kext or the kernel main executable. |
834 | * Logd uses copyKextUUIDForAddress with the addr specified |
835 | * in the log line to retrieve the kext UUID of the sender. |
836 | * |
837 | * Dext however are not loaded in kernel space so they do not |
838 | * have a kernel range of addresses. |
839 | * |
840 | * To make the same mechanism work, OSKext fakes a kernel |
841 | * address range for dexts using the loadTag, |
842 | * so we just need to use the loadTag as addr here |
843 | * to allow logd to retrieve the correct UUID. |
844 | * |
845 | * NOTE: loadTag is populated in the task when the dext is matching, |
846 | * so if log lines are generated before the matching they will be |
847 | * identified as kernel main executable. |
848 | */ |
849 | task_t self_task = current_task(); |
850 | |
851 | /* |
852 | * Only dexts are supposed to use this log path. Verified in log_data() |
853 | * but worth of another check here in case this function gets called |
854 | * directly. |
855 | */ |
856 | if (!task_is_driver(task: self_task)) { |
857 | return EPERM; |
858 | } |
859 | |
860 | uint64_t loadTag = get_task_loadTag(task: self_task); |
861 | if (loadTag != 0) { |
862 | driverKitLog = TRUE; |
863 | addr = (void *)loadTag; |
864 | } |
865 | |
866 | va_start(args, fmt); |
867 | _os_log_with_args_internal(oslog: log, type, fmt, args, ts, addr, dso, driverKit: driverKitLog, true); |
868 | va_end(args); |
869 | |
870 | return 0; |
871 | } |
872 | |
873 | __attribute__((noinline, not_tail_called)) void |
874 | os_log_with_args(os_log_t oslog, os_log_type_t type, const char *fmt, |
875 | va_list args, void *addr) |
876 | { |
877 | uint64_t ts = firehose_tracepoint_time(flags: firehose_activity_flags_default); |
878 | |
879 | // if no address passed, look it up |
880 | if (addr == NULL) { |
881 | addr = __builtin_return_address(0); |
882 | } |
883 | |
884 | _os_log_with_args_internal(oslog, type, fmt, args, ts, addr, NULL, FALSE, FALSE); |
885 | } |
886 | |
887 | bool |
888 | os_log_coprocessor(void *buff, uint64_t buff_len, os_log_type_t type, |
889 | const char *uuid, uint64_t timestamp, uint32_t offset, bool stream_log) |
890 | { |
891 | counter_inc(&oslog_p_coprocessor_total_msgcount); |
892 | |
893 | if (os_log_turned_off() || !os_log_safe()) { |
894 | counter_inc(&oslog_p_coprocessor_dropped_msgcount); |
895 | return false; |
896 | } |
897 | |
898 | if (buff_len + 16 + sizeof(uint32_t) > OS_LOG_BUFFER_MAX_SIZE) { |
899 | counter_inc(&oslog_p_coprocessor_dropped_msgcount); |
900 | return false; |
901 | } |
902 | |
903 | __attribute__((uninitialized)) |
904 | uint8_t pubdata[OS_LOG_BUFFER_MAX_SIZE]; |
905 | size_t wr_pos = 0; |
906 | |
907 | memcpy(dst: pubdata, src: &offset, n: sizeof(uint32_t)); |
908 | wr_pos += sizeof(uint32_t); |
909 | memcpy(dst: pubdata + wr_pos, src: uuid, n: 16); |
910 | wr_pos += 16; |
911 | |
912 | memcpy(dst: pubdata + wr_pos, src: buff, n: buff_len); |
913 | wr_pos += buff_len; |
914 | |
915 | /* |
916 | * Unlike KEXTs, where PC is used to find UUID, in coprocessor logs the UUID |
917 | * is passed as part of the tracepoint. |
918 | */ |
919 | firehose_tracepoint_namespace_t ns = firehose_tracepoint_namespace_log; |
920 | firehose_tracepoint_flags_t flags = _firehose_tracepoint_flags_pc_style_uuid_relative; |
921 | firehose_tracepoint_id_u trace_id = { |
922 | .ftid_value = FIREHOSE_TRACE_ID_MAKE(ns, type, flags, offset) |
923 | }; |
924 | |
925 | log_payload_s log; |
926 | log_payload_init(lp: &log, stream: firehose_stream(type), ftid: trace_id, timestamp, data_size: wr_pos, pub_data_size: wr_pos); |
927 | |
928 | if (!log_queue_log(&log, pubdata, stream_log)) { |
929 | counter_inc(&oslog_p_coprocessor_dropped_msgcount); |
930 | return false; |
931 | } |
932 | |
933 | return true; |
934 | } |
935 | |
936 | static inline firehose_tracepoint_t |
937 | firehose_trace_start(const log_payload_s *lp, uint8_t **ft_priv_data) |
938 | { |
939 | uint16_t priv_data_size = (uint16_t)log_payload_priv_data_size(lp); |
940 | uint16_t pub_data_size = (uint16_t)lp->lp_pub_data_size; |
941 | |
942 | if (priv_data_size > 0) { |
943 | pub_data_size += sizeof(struct firehose_buffer_range_s); |
944 | } |
945 | |
946 | assert3u(offsetof(struct firehose_tracepoint_s, ft_data) + |
947 | pub_data_size + priv_data_size, <=, sizeof(((firehose_chunk_t)0)->fc_data)); |
948 | |
949 | firehose_tracepoint_t ft = __firehose_buffer_tracepoint_reserve(stamp: lp->lp_timestamp, |
950 | stream: lp->lp_stream, pubsize: pub_data_size, privsize: priv_data_size, privptr: ft_priv_data); |
951 | |
952 | if (fastpath(ft)) { |
953 | oslog_boot_done = true; |
954 | return ft; |
955 | } |
956 | |
957 | if (fastpath(oslog_boot_done)) { |
958 | return 0; |
959 | } |
960 | |
961 | /* |
962 | * Early boot logging when kernel logging is up and running but logd is |
963 | * not yet ready. Only the persist firehose stream is available. |
964 | */ |
965 | |
966 | long offset = firehose_chunk_tracepoint_try_reserve(fc: &firehose_boot_chunk, |
967 | stamp: lp->lp_timestamp, stream: firehose_stream_persist, qos: 0, pubsize: pub_data_size, |
968 | privsize: priv_data_size, privptr: ft_priv_data); |
969 | if (offset <= 0) { |
970 | counter_inc(&oslog_p_boot_dropped_msgcount); |
971 | return 0; |
972 | } |
973 | |
974 | return firehose_chunk_tracepoint_begin(fc: &firehose_boot_chunk, |
975 | stamp: lp->lp_timestamp, pubsize: pub_data_size, thread_id: thread_tid(thread: current_thread()), |
976 | offset); |
977 | } |
978 | |
979 | static inline void |
980 | firehose_trace_finish(firehose_tracepoint_t ft, firehose_tracepoint_id_u ftid) |
981 | { |
982 | if (__probable(oslog_boot_done)) { |
983 | __firehose_buffer_tracepoint_flush(vat: ft, vatid: ftid); |
984 | } else { |
985 | firehose_chunk_tracepoint_end(fc: &firehose_boot_chunk, ft, ftid); |
986 | } |
987 | } |
988 | |
989 | static inline void |
990 | firehose_trace_save_payload(const log_payload_s *lp, const uint8_t *lp_data, |
991 | firehose_tracepoint_t ft, uint8_t *ft_priv_data) |
992 | { |
993 | const size_t priv_data_size = log_payload_priv_data_size(lp); |
994 | uint8_t *ft_data = ft->ft_data; |
995 | |
996 | if (priv_data_size > 0) { |
997 | assert(FIREHOSE_TRACE_ID_HAS_FLAG(lp->lp_ftid, log, has_private_data)); |
998 | memcpy(dst: ft_priv_data, src: log_payload_priv_data(lp, lp_data), n: priv_data_size); |
999 | |
1000 | firehose_chunk_t fc = firehose_chunk_for_address(addr: ft); |
1001 | struct firehose_buffer_range_s range = { |
1002 | .fbr_offset = (uint16_t)(ft_priv_data - fc->fc_start), |
1003 | .fbr_length = (uint16_t)priv_data_size |
1004 | }; |
1005 | memcpy(dst: ft_data, src: &range, n: sizeof(range)); |
1006 | ft_data += sizeof(range); |
1007 | } |
1008 | memcpy(dst: ft_data, src: lp_data, n: lp->lp_pub_data_size); |
1009 | } |
1010 | |
1011 | static inline void |
1012 | log_stats_update_saved(firehose_stream_t stream) |
1013 | { |
1014 | if (__improbable(!oslog_boot_done)) { |
1015 | stream = firehose_stream_persist; |
1016 | } |
1017 | |
1018 | switch (stream) { |
1019 | case firehose_stream_metadata: |
1020 | counter_inc(&oslog_p_metadata_saved_msgcount); |
1021 | break; |
1022 | case firehose_stream_persist: |
1023 | case firehose_stream_memory: |
1024 | counter_inc(&oslog_p_saved_msgcount); |
1025 | break; |
1026 | case firehose_stream_signpost: |
1027 | counter_inc(&oslog_p_signpost_saved_msgcount); |
1028 | break; |
1029 | default: |
1030 | panic("Unexpected firehose stream type %u" , stream); |
1031 | } |
1032 | } |
1033 | |
1034 | static inline firehose_tracepoint_id_t |
1035 | firehose_trace(const log_payload_s *lp, const uint8_t *lp_data) |
1036 | { |
1037 | uint8_t *ft_priv_data = NULL; |
1038 | firehose_tracepoint_t ft = firehose_trace_start(lp, ft_priv_data: &ft_priv_data); |
1039 | |
1040 | if (fastpath(ft)) { |
1041 | firehose_trace_save_payload(lp, lp_data, ft, ft_priv_data); |
1042 | firehose_trace_finish(ft, ftid: lp->lp_ftid); |
1043 | log_stats_update_saved(stream: lp->lp_stream); |
1044 | return lp->lp_ftid.ftid_value; |
1045 | } |
1046 | return 0; |
1047 | } |
1048 | |
1049 | static firehose_tracepoint_code_t |
1050 | coproc_reg_type_to_firehost_code(os_log_coproc_reg_t reg_type) |
1051 | { |
1052 | switch (reg_type) { |
1053 | case os_log_coproc_register_memory: |
1054 | return firehose_tracepoint_code_load_memory; |
1055 | case os_log_coproc_register_harvest_fs_ftab: |
1056 | return firehose_tracepoint_code_load_filesystem_ftab; |
1057 | default: |
1058 | return firehose_tracepoint_code_invalid; |
1059 | } |
1060 | } |
1061 | |
1062 | void |
1063 | os_log_coprocessor_register_with_type(const char *uuid, const char *file_path, os_log_coproc_reg_t reg_type) |
1064 | { |
1065 | size_t path_size = strlen(s: file_path) + 1; |
1066 | size_t uuid_info_len = sizeof(struct firehose_trace_uuid_info_s) + path_size; |
1067 | |
1068 | if (os_log_disabled() || path_size > PATH_MAX) { |
1069 | return; |
1070 | } |
1071 | |
1072 | __attribute__((uninitialized)) |
1073 | union { |
1074 | struct firehose_trace_uuid_info_s uuid_info; |
1075 | char path[PATH_MAX + sizeof(struct firehose_trace_uuid_info_s)]; |
1076 | } buf; |
1077 | |
1078 | // write metadata to uuid_info |
1079 | memcpy(dst: buf.uuid_info.ftui_uuid, src: uuid, n: sizeof(uuid_t)); |
1080 | buf.uuid_info.ftui_size = 1; |
1081 | buf.uuid_info.ftui_address = 1; |
1082 | |
1083 | uint64_t stamp = firehose_tracepoint_time(flags: firehose_activity_flags_default); |
1084 | |
1085 | // create tracepoint id |
1086 | firehose_tracepoint_id_u trace_id; |
1087 | trace_id.ftid_value = FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_metadata, |
1088 | _firehose_tracepoint_type_metadata_coprocessor, (firehose_tracepoint_flags_t)0, |
1089 | coproc_reg_type_to_firehost_code(reg_type)); |
1090 | |
1091 | // write path to buffer |
1092 | memcpy(dst: buf.uuid_info.ftui_path, src: file_path, n: path_size); |
1093 | |
1094 | // send metadata tracepoint to firehose for coprocessor registration in logd |
1095 | os_log_encoded_metadata(ftid: trace_id, ts: stamp, msg: (void *)&buf, msg_size: uuid_info_len); |
1096 | } |
1097 | |
1098 | bool |
1099 | log_payload_send(log_payload_t lp, const void *lp_data, bool use_stream) |
1100 | { |
1101 | if (use_stream) { |
1102 | bool is_metadata = (lp->lp_stream == firehose_stream_metadata); |
1103 | oslog_stream(is_metadata, lp->lp_ftid, lp->lp_timestamp, lp_data, lp->lp_data_size); |
1104 | } |
1105 | return firehose_trace(lp, lp_data) != 0; |
1106 | } |
1107 | |
1108 | void |
1109 | __firehose_buffer_push_to_logd(firehose_buffer_t fb __unused, bool for_io __unused) |
1110 | { |
1111 | oslogwakeup(); |
1112 | return; |
1113 | } |
1114 | |
1115 | void |
1116 | __firehose_allocate(vm_offset_t *addr, vm_size_t size __unused) |
1117 | { |
1118 | firehose_chunk_t kernel_buffer = (firehose_chunk_t)kernel_firehose_addr; |
1119 | |
1120 | if (kernel_firehose_addr) { |
1121 | *addr = kernel_firehose_addr; |
1122 | } else { |
1123 | *addr = 0; |
1124 | return; |
1125 | } |
1126 | // Now that we are done adding logs to this chunk, set the number of writers to 0 |
1127 | // Without this, logd won't flush when the page is full |
1128 | firehose_boot_chunk.fc_pos.fcp_refcnt = 0; |
1129 | memcpy(dst: &kernel_buffer[FIREHOSE_BUFFER_KERNEL_CHUNK_COUNT - 1], src: (const void *)&firehose_boot_chunk, FIREHOSE_CHUNK_SIZE); |
1130 | return; |
1131 | } |
1132 | // There isnt a lock held in this case. |
1133 | void |
1134 | __firehose_critical_region_enter(void) |
1135 | { |
1136 | disable_preemption(); |
1137 | return; |
1138 | } |
1139 | |
1140 | void |
1141 | __firehose_critical_region_leave(void) |
1142 | { |
1143 | enable_preemption(); |
1144 | return; |
1145 | } |
1146 | |
1147 | #ifdef CONFIG_XNUPOST |
1148 | |
1149 | static_assert(&_os_log_default == OS_LOG_DEFAULT, |
1150 | "OS_LOG_DEFAULT is an alias to _os_log_default" ); |
1151 | static_assert(OS_LOG_DISABLED == NULL, |
1152 | "OS_LOG_DISABLED handle is defined as NULL" ); |
1153 | |
1154 | #include <dev/random/randomdev.h> |
1155 | #include <tests/xnupost.h> |
1156 | |
1157 | typedef struct { |
1158 | size_t total; |
1159 | size_t saved; |
1160 | size_t dropped; |
1161 | size_t truncated; |
1162 | size_t errors; |
1163 | size_t errors_kc; |
1164 | size_t errors_fmt; |
1165 | size_t errors_max_args; |
1166 | } log_stats_t; |
1167 | |
1168 | #define TESTBUFLEN 256 |
1169 | #define TESTOSLOGFMT(fn_name) "%u^%llu/%llu^kernel^0^test^" fn_name |
1170 | #define TESTOSLOGPFX "TESTLOG:%u#" |
1171 | #define TESTOSLOG(fn_name) TESTOSLOGPFX TESTOSLOGFMT(fn_name "#") |
1172 | |
1173 | #define LOG_STAT_CMP(cmp, b, a, e, stat, msg, test) \ |
1174 | { \ |
1175 | size_t n##stat = (a)->stat - (b)->stat; \ |
1176 | size_t n##expected = (e)->stat; \ |
1177 | cmp(n##stat, n##expected, (msg), (test), n##expected); \ |
1178 | } |
1179 | #define LOG_STAT_EQ(b, a, e, stat, msg, test) \ |
1180 | LOG_STAT_CMP(T_EXPECT_EQ_UINT, b, a, e, stat, msg, test) |
1181 | #define LOG_STAT_GE(b, a, e, stat, msg, test) \ |
1182 | LOG_STAT_CMP(T_EXPECT_GE_UINT, b, a, e, stat, msg, test) |
1183 | |
1184 | #define GENOSLOGHELPER(fname, ident, callout_f) \ |
1185 | static void \ |
1186 | fname(uint32_t uniqid, uint64_t count, log_stats_t *before, log_stats_t *after) \ |
1187 | { \ |
1188 | uint32_t checksum = 0; \ |
1189 | char pattern[TESTBUFLEN]; \ |
1190 | T_LOG("Testing " ident "() with %d logs", count); \ |
1191 | log_stats_get(before); \ |
1192 | for (uint64_t i = 0; i < count; i++) { \ |
1193 | (void) save_pattern(pattern, &checksum, TESTOSLOGFMT(ident), uniqid, i + 1, count); \ |
1194 | callout_f(OS_LOG_DEFAULT, TESTOSLOG(ident), checksum, uniqid, i + 1, count); \ |
1195 | } \ |
1196 | log_stats_get(after); \ |
1197 | } |
1198 | |
1199 | extern size_t find_pattern_in_buffer(const char *, size_t, size_t); |
1200 | |
1201 | void test_oslog_handleOSLogCtl(int32_t *, int32_t *, int32_t); |
1202 | kern_return_t test_printf(void); |
1203 | kern_return_t test_os_log(void); |
1204 | kern_return_t test_os_log_handles(void); |
1205 | kern_return_t test_os_log_parallel(void); |
1206 | |
1207 | SCALABLE_COUNTER_DECLARE(oslog_p_fmt_invalid_msgcount); |
1208 | SCALABLE_COUNTER_DECLARE(oslog_p_fmt_max_args_msgcount); |
1209 | SCALABLE_COUNTER_DECLARE(oslog_p_truncated_msgcount); |
1210 | SCALABLE_COUNTER_DECLARE(log_queue_cnt_received); |
1211 | |
1212 | static void |
1213 | log_stats_get(log_stats_t *stats) |
1214 | { |
1215 | if (!stats) { |
1216 | return; |
1217 | } |
1218 | stats->total = counter_load(&oslog_p_total_msgcount); |
1219 | stats->saved = counter_load(&log_queue_cnt_received); |
1220 | stats->dropped = counter_load(&oslog_p_dropped_msgcount); |
1221 | stats->truncated = counter_load(&oslog_p_truncated_msgcount); |
1222 | stats->errors = counter_load(&oslog_p_error_count); |
1223 | stats->errors_kc = counter_load(&oslog_p_unresolved_kc_msgcount); |
1224 | stats->errors_fmt = counter_load(&oslog_p_fmt_invalid_msgcount); |
1225 | stats->errors_max_args = counter_load(&oslog_p_fmt_max_args_msgcount); |
1226 | } |
1227 | |
1228 | static void |
1229 | log_stats_diff(const log_stats_t *before, const log_stats_t *after, log_stats_t *diff) |
1230 | { |
1231 | log_stats_t d = {}; |
1232 | |
1233 | if (before) { |
1234 | d = *before; |
1235 | } |
1236 | if (after) { |
1237 | d.total = after->total - d.total; |
1238 | d.saved = after->saved - d.saved; |
1239 | d.dropped = after->dropped - d.dropped; |
1240 | d.truncated = after->truncated - d.truncated; |
1241 | d.errors = after->errors - d.errors; |
1242 | d.errors_kc = after->errors_kc - d.errors_kc; |
1243 | d.errors_fmt = after->errors_fmt - d.errors_fmt; |
1244 | d.errors_max_args = after->errors_max_args - d.errors_max_args; |
1245 | } |
1246 | *diff = d; |
1247 | } |
1248 | |
1249 | static void |
1250 | log_stats_check_errors(const log_stats_t *before, const log_stats_t *after, const log_stats_t *expected, |
1251 | const char *test) |
1252 | { |
1253 | LOG_STAT_EQ(before, after, expected, errors, "%s: Expected %lu encoding errors" , test); |
1254 | LOG_STAT_EQ(before, after, expected, errors_kc, "%s: Expected %lu DSO errors" , test); |
1255 | LOG_STAT_EQ(before, after, expected, errors_fmt, "%s: Expected %lu bad format errors" , test); |
1256 | LOG_STAT_EQ(before, after, expected, errors_max_args, "%s: Expected %lu max arguments errors" , test); |
1257 | } |
1258 | |
1259 | static void |
1260 | log_stats_check(const log_stats_t *before, const log_stats_t *after, const log_stats_t *expected, |
1261 | const char *test) |
1262 | { |
1263 | /* |
1264 | * The comparison is >= (_GE) for total and saved counters because tests |
1265 | * are running while the system is up and potentially logging. Test and |
1266 | * regular logs interfere rather rarely but can make the test flaky |
1267 | * which is not desired. |
1268 | */ |
1269 | LOG_STAT_GE(before, after, expected, total, "%s: Expected %lu logs total" , test); |
1270 | LOG_STAT_GE(before, after, expected, saved, "%s: Expected %lu saved logs" , test); |
1271 | LOG_STAT_EQ(before, after, expected, dropped, "%s: Expected %lu logs dropped" , test); |
1272 | log_stats_check_errors(before, after, expected, test); |
1273 | } |
1274 | |
1275 | static void |
1276 | log_stats_report(const log_stats_t *before, const log_stats_t *after, const char *test) |
1277 | { |
1278 | log_stats_t diff = {}; |
1279 | log_stats_diff(before, after, &diff); |
1280 | |
1281 | T_LOG("\n%s: Logging stats:\n\ttotal: %u\n\tsaved: %u\n\tdropped: %u\n" |
1282 | "\terrors: %u\n\terrors_kc: %u\n\terrors_fmt: %u\n\terrors_max_args: %u" , |
1283 | test, diff.total, diff.saved, diff.dropped, |
1284 | diff.errors, diff.errors_kc, diff.errors_fmt, diff.errors_max_args); |
1285 | } |
1286 | |
1287 | static int |
1288 | save_pattern(char buf[static TESTBUFLEN], uint32_t *crc, const char *fmt, ...) |
1289 | { |
1290 | va_list va; |
1291 | |
1292 | va_start(va, fmt); |
1293 | #pragma clang diagnostic push |
1294 | #pragma clang diagnostic ignored "-Wformat-nonliteral" |
1295 | int n = vscnprintf(buf, TESTBUFLEN, fmt, va); |
1296 | #pragma clang diagnostic pop |
1297 | va_end(va); |
1298 | if (crc) { |
1299 | *crc = crc32(0, buf, n); |
1300 | } |
1301 | return n; |
1302 | } |
1303 | |
1304 | /* |
1305 | * Actual GENOSLOGHELPER() 2nd argument values below are expected by libtrace |
1306 | * test_kern_oslog test suite and shall not be changed without updating given |
1307 | * test suite. |
1308 | */ |
1309 | GENOSLOGHELPER(test_oslog_info, "oslog_info_helper" , os_log_info); |
1310 | GENOSLOGHELPER(test_oslog_fault, "oslog_fault_helper" , os_log_fault); |
1311 | GENOSLOGHELPER(test_oslog_debug, "oslog_debug_helper" , os_log_debug); |
1312 | GENOSLOGHELPER(test_oslog_error, "oslog_error_helper" , os_log_error); |
1313 | GENOSLOGHELPER(test_oslog_default, "oslog_default_helper" , os_log); |
1314 | |
1315 | kern_return_t |
1316 | test_printf(void) |
1317 | { |
1318 | const uint32_t uniqid = RandomULong(); |
1319 | T_ASSERT_NE_UINT(0, uniqid, "Random number should not be zero" ); |
1320 | |
1321 | uint64_t stamp = mach_absolute_time(); |
1322 | T_ASSERT_NE_ULLONG(0, stamp, "Absolute time should not be zero" ); |
1323 | |
1324 | T_LOG("Validating with atm_diagnostic_config=%#x uniqid=%u stamp=%llu" , |
1325 | atm_get_diagnostic_config(), uniqid, stamp); |
1326 | |
1327 | __attribute__((uninitialized)) |
1328 | char pattern[TESTBUFLEN]; |
1329 | log_stats_t before = {}, after = {}; |
1330 | uint32_t checksum = 0; |
1331 | |
1332 | log_stats_get(&before); |
1333 | |
1334 | (void) save_pattern(pattern, &checksum, TESTOSLOGFMT("printf_only" ), uniqid, 1LL, 2LL); |
1335 | printf(TESTOSLOG("printf_only" ) "mat%llu\n" , checksum, uniqid, 1LL, 2LL, stamp); |
1336 | |
1337 | (void) save_pattern(pattern, &checksum, TESTOSLOGFMT("printf_only" ), uniqid, 2LL, 2LL); |
1338 | printf(TESTOSLOG("printf_only" ) "mat%llu\n" , checksum, uniqid, 2LL, 2LL, stamp); |
1339 | |
1340 | size_t saved = save_pattern(pattern, NULL, "kernel^0^test^printf_only#mat%llu" , stamp); |
1341 | size_t match_count = find_pattern_in_buffer(pattern, saved, 2LL); |
1342 | T_EXPECT_EQ_ULONG(match_count, 2LL, "printf() logs to msgbuf" ); |
1343 | |
1344 | log_stats_get(&after); |
1345 | |
1346 | if (!os_log_turned_off()) { |
1347 | // printf() should log to OSLog with OSLog enabled. |
1348 | log_stats_t expected = { .total = 2, .saved = 2 }; |
1349 | log_stats_check(&before, &after, &expected, "printf() logs to oslog" ); |
1350 | } |
1351 | |
1352 | log_stats_report(&before, &after, __FUNCTION__); |
1353 | |
1354 | return KERN_SUCCESS; |
1355 | } |
1356 | |
1357 | static void |
1358 | verify_os_log(struct os_log_s *h, char *sub, char *cat) |
1359 | { |
1360 | const size_t sub_len = os_log_subsystem_name_size(sub); |
1361 | const size_t cat_len = os_log_subsystem_name_size(cat); |
1362 | |
1363 | struct os_log_subsystem_s *s = &h->ol_subsystem; |
1364 | |
1365 | T_ASSERT_EQ_STR(s->ols_name, sub, "Log subsystem name is %s" , sub); |
1366 | T_ASSERT_EQ_ULONG(s->ols_sub_size, sub_len, "Log subsystem size is %lu" , sub_len); |
1367 | T_ASSERT_EQ_ULONG(strlen(s->ols_name), sub_len - 1, "Log subsystem length is %lu" , sub_len - 1); |
1368 | |
1369 | T_ASSERT_EQ_STR(&s->ols_name[sub_len], cat, "Log category name is %s" , cat); |
1370 | T_ASSERT_EQ_ULONG(s->ols_cat_size, cat_len, "Log category length is %lu" , cat_len); |
1371 | T_ASSERT_EQ_ULONG(strlen(&s->ols_name[sub_len]), cat_len - 1, "Log category size is %lu" , cat_len - 1); |
1372 | } |
1373 | |
1374 | static os_log_t |
1375 | create_verified_os_log(char *sub, char *cat) |
1376 | { |
1377 | os_log_t h = os_log_create(sub, cat); |
1378 | verify_os_log(h, sub, cat); |
1379 | return h; |
1380 | } |
1381 | |
1382 | kern_return_t |
1383 | test_os_log_handles(void) |
1384 | { |
1385 | os_log_t h1 = create_verified_os_log("xnu_post_subsystem1" , "xnu_post_category1" ); |
1386 | if (os_log_disabled()) { |
1387 | T_ASSERT_EQ_PTR(h1, OS_LOG_DISABLED, "Disabled logging uses OS_LOG_DISABLED" ); |
1388 | return KERN_SUCCESS; |
1389 | } |
1390 | T_ASSERT_NE_PTR(h1, OS_LOG_DEFAULT, "Custom log handle is not OS_LOG_DEFAULT" ); |
1391 | |
1392 | os_log_t h2 = create_verified_os_log("xnu_post_subsystem1" , "xnu_post_category1" ); |
1393 | T_ASSERT_EQ_PTR(h1, h2, "os_log_create() finds an existing log handle in the cache" ); |
1394 | |
1395 | h2 = create_verified_os_log("xnu_post_subsystem1" , "xnu_post_category2" ); |
1396 | T_ASSERT_NE_PTR(h1, h2, "Subsystem is not enough to identify a log handle" ); |
1397 | |
1398 | h2 = create_verified_os_log("xnu_post_subsystem2" , "xnu_post_category1" ); |
1399 | T_ASSERT_NE_PTR(h1, h2, "Category is not enough to identify a log handle" ); |
1400 | |
1401 | h2 = create_verified_os_log("xnu_post_subsystem3" , "xnu_post_category3" ); |
1402 | T_ASSERT_NE_PTR(h1, h2, "Different subsystem and category yield a different handle" ); |
1403 | |
1404 | h1 = h2; |
1405 | h2 = create_verified_os_log("xnu_post" , "_subsystem3xnu_post_category3" ); |
1406 | T_ASSERT_NE_PTR(h1, h2, "Subsystem and category cannot be mixed" ); |
1407 | |
1408 | const size_t name_size = sizeof(h1->ol_subsystem.ols_name) / 2; |
1409 | |
1410 | char super_long_sub[name_size] = { |
1411 | [0 ... sizeof(super_long_sub) - 1] = 'X' |
1412 | }; |
1413 | |
1414 | char super_long_cat[name_size] = { |
1415 | [0 ... sizeof(super_long_sub) - 1] = 'Y' |
1416 | }; |
1417 | |
1418 | h1 = os_log_create(super_long_sub, super_long_cat); |
1419 | T_ASSERT_NE_PTR(h1, OS_LOG_DEFAULT, "Custom log handle is not OS_LOG_DEFAULT" ); |
1420 | |
1421 | super_long_sub[name_size - 1] = '\0'; |
1422 | super_long_cat[name_size - 1] = '\0'; |
1423 | |
1424 | verify_os_log(h1, super_long_sub, super_long_cat); |
1425 | |
1426 | return KERN_SUCCESS; |
1427 | } |
1428 | |
1429 | kern_return_t |
1430 | test_os_log(void) |
1431 | { |
1432 | const uint32_t uniqid = RandomULong(); |
1433 | T_ASSERT_NE_UINT(0, uniqid, "Random number should not be zero" ); |
1434 | |
1435 | uint64_t stamp = mach_absolute_time(); |
1436 | T_ASSERT_NE_ULLONG(0, stamp, "Absolute time should not be zero" ); |
1437 | |
1438 | T_LOG("Validating with atm_diagnostic_config=%#x uniqid=%u stamp=%llu" , |
1439 | atm_get_diagnostic_config(), uniqid, stamp); |
1440 | |
1441 | os_log_t log_handle = os_log_create("com.apple.xnu.test.t1" , "kpost" ); |
1442 | T_ASSERT_NE_PTR(OS_LOG_DEFAULT, log_handle, "Log handle is not OS_LOG_DEFAULT" ); |
1443 | |
1444 | const bool enabled = !os_log_turned_off(); |
1445 | T_ASSERT_EQ_INT(enabled, os_log_info_enabled(log_handle), "Info log level is enabled" ); |
1446 | T_ASSERT_EQ_INT(enabled, os_log_debug_enabled(log_handle), "Debug log level is enabled" ); |
1447 | |
1448 | __attribute__((uninitialized)) |
1449 | char pattern[TESTBUFLEN]; |
1450 | uint32_t checksum = 0; |
1451 | |
1452 | (void) save_pattern(pattern, &checksum, TESTOSLOGFMT("oslog_info" ), uniqid, 1LL, 1LL); |
1453 | os_log_info(log_handle, TESTOSLOG("oslog_info" ) "mat%llu" , checksum, uniqid, 1LL, 1LL, stamp); |
1454 | size_t saved = save_pattern(pattern, NULL, "kernel^0^test^oslog_info#mat%llu" , stamp); |
1455 | size_t match_count = find_pattern_in_buffer(pattern, saved, 1LL); |
1456 | T_EXPECT_EQ_ULONG(match_count, 1LL, "oslog_info() logs to system message buffer" ); |
1457 | |
1458 | const size_t n = 10; |
1459 | |
1460 | log_stats_t expected = { |
1461 | .total = enabled ? n : 0, |
1462 | .saved = enabled ? n : 0 |
1463 | }; |
1464 | |
1465 | log_stats_t before = {}, after = {}; |
1466 | |
1467 | test_oslog_info(uniqid, n, &before, &after); |
1468 | log_stats_check(&before, &after, &expected, "test_oslog_info" ); |
1469 | |
1470 | test_oslog_debug(uniqid, n, &before, &after); |
1471 | log_stats_check(&before, &after, &expected, "test_oslog_debug" ); |
1472 | |
1473 | test_oslog_error(uniqid, n, &before, &after); |
1474 | log_stats_check(&before, &after, &expected, "test_oslog_error" ); |
1475 | |
1476 | test_oslog_default(uniqid, n, &before, &after); |
1477 | log_stats_check(&before, &after, &expected, "test_oslog_default" ); |
1478 | |
1479 | test_oslog_fault(uniqid, n, &before, &after); |
1480 | log_stats_check(&before, &after, &expected, "test_oslog_fault" ); |
1481 | |
1482 | log_stats_report(&before, &after, __FUNCTION__); |
1483 | |
1484 | return KERN_SUCCESS; |
1485 | } |
1486 | |
1487 | static size_t _test_log_loop_count = 0; |
1488 | |
1489 | static void |
1490 | _test_log_loop(void *arg __unused, wait_result_t wres __unused) |
1491 | { |
1492 | test_oslog_debug(RandomULong(), 100, NULL, NULL); |
1493 | os_atomic_add(&_test_log_loop_count, 100, relaxed); |
1494 | } |
1495 | |
1496 | kern_return_t |
1497 | test_os_log_parallel(void) |
1498 | { |
1499 | if (os_log_turned_off()) { |
1500 | T_LOG("Logging disabled, skipping tests." ); |
1501 | return KERN_SUCCESS; |
1502 | } |
1503 | |
1504 | thread_t thread[2]; |
1505 | kern_return_t kr; |
1506 | log_stats_t after, before, expected = {}; |
1507 | |
1508 | log_stats_get(&before); |
1509 | |
1510 | kr = kernel_thread_start(_test_log_loop, NULL, &thread[0]); |
1511 | T_ASSERT_EQ_INT(kr, KERN_SUCCESS, "kernel_thread_start returned successfully" ); |
1512 | |
1513 | kr = kernel_thread_start(_test_log_loop, NULL, &thread[1]); |
1514 | T_ASSERT_EQ_INT(kr, KERN_SUCCESS, "kernel_thread_start returned successfully" ); |
1515 | |
1516 | test_oslog_info(RandomULong(), 100, NULL, NULL); |
1517 | |
1518 | /* wait until other thread has also finished */ |
1519 | while (_test_log_loop_count < 200) { |
1520 | delay(1000); |
1521 | } |
1522 | |
1523 | thread_deallocate(thread[0]); |
1524 | thread_deallocate(thread[1]); |
1525 | |
1526 | log_stats_get(&after); |
1527 | log_stats_check_errors(&before, &after, &expected, __FUNCTION__); |
1528 | log_stats_report(&before, &after, __FUNCTION__); |
1529 | |
1530 | return KERN_SUCCESS; |
1531 | } |
1532 | |
1533 | static kern_return_t |
1534 | test_stresslog_dropmsg(const uint32_t uniqid) |
1535 | { |
1536 | if (os_log_turned_off()) { |
1537 | T_LOG("Logging disabled, skipping tests." ); |
1538 | return KERN_SUCCESS; |
1539 | } |
1540 | |
1541 | log_stats_t after, before, expected = {}; |
1542 | |
1543 | test_oslog_debug(uniqid, 100, &before, &after); |
1544 | while ((after.dropped - before.dropped) == 0) { |
1545 | test_oslog_debug(uniqid, 100, NULL, &after); |
1546 | } |
1547 | |
1548 | log_stats_check_errors(&before, &after, &expected, __FUNCTION__); |
1549 | log_stats_report(&before, &after, __FUNCTION__); |
1550 | |
1551 | return KERN_SUCCESS; |
1552 | } |
1553 | |
1554 | void |
1555 | test_oslog_handleOSLogCtl(int32_t *in, int32_t *out, int32_t len) |
1556 | { |
1557 | if (!in || !out || len != 4) { |
1558 | return; |
1559 | } |
1560 | switch (in[0]) { |
1561 | case 1: |
1562 | { |
1563 | /* send out counters */ |
1564 | out[1] = counter_load(&oslog_p_total_msgcount); |
1565 | out[2] = counter_load(&oslog_p_saved_msgcount); |
1566 | out[3] = counter_load(&oslog_p_dropped_msgcount); |
1567 | out[0] = KERN_SUCCESS; |
1568 | break; |
1569 | } |
1570 | case 2: |
1571 | { |
1572 | /* mini stress run */ |
1573 | out[0] = test_os_log_parallel(); |
1574 | break; |
1575 | } |
1576 | case 3: |
1577 | { |
1578 | /* drop msg tests */ |
1579 | out[1] = RandomULong(); |
1580 | out[0] = test_stresslog_dropmsg(out[1]); |
1581 | break; |
1582 | } |
1583 | case 4: |
1584 | { |
1585 | /* invoke log helpers */ |
1586 | uint32_t uniqid = in[3]; |
1587 | int32_t msgcount = in[2]; |
1588 | if (uniqid == 0 || msgcount == 0) { |
1589 | out[0] = KERN_INVALID_VALUE; |
1590 | return; |
1591 | } |
1592 | |
1593 | switch (in[1]) { |
1594 | case OS_LOG_TYPE_INFO: |
1595 | test_oslog_info(uniqid, msgcount, NULL, NULL); |
1596 | break; |
1597 | case OS_LOG_TYPE_DEBUG: |
1598 | test_oslog_debug(uniqid, msgcount, NULL, NULL); |
1599 | break; |
1600 | case OS_LOG_TYPE_ERROR: |
1601 | test_oslog_error(uniqid, msgcount, NULL, NULL); |
1602 | break; |
1603 | case OS_LOG_TYPE_FAULT: |
1604 | test_oslog_fault(uniqid, msgcount, NULL, NULL); |
1605 | break; |
1606 | case OS_LOG_TYPE_DEFAULT: |
1607 | default: |
1608 | test_oslog_default(uniqid, msgcount, NULL, NULL); |
1609 | break; |
1610 | } |
1611 | out[0] = KERN_SUCCESS; |
1612 | break; |
1613 | /* end of case 4 */ |
1614 | } |
1615 | default: |
1616 | { |
1617 | out[0] = KERN_INVALID_VALUE; |
1618 | break; |
1619 | } |
1620 | } |
1621 | return; |
1622 | } |
1623 | |
1624 | #endif /* CONFIG_XNUPOST */ |
1625 | |