X-Git-Url: https://git.saurik.com/apple/xnu.git/blobdiff_plain/a1c7dba18ef36983396c282fe85292db066e39db..d190cdc3f5544636abb56dc1874be391d3e1b148:/bsd/kern/kdebug.c diff --git a/bsd/kern/kdebug.c b/bsd/kern/kdebug.c index 1b89e2d4a..6d7fc0902 100644 --- a/bsd/kern/kdebug.c +++ b/bsd/kern/kdebug.c @@ -1,14 +1,14 @@ /* - * Copyright (c) 2000-2013 Apple Inc. All rights reserved. + * Copyright (c) 2000-2016 Apple Inc. All rights reserved. * * @Apple_LICENSE_HEADER_START@ - * + * * The contents of this file constitute Original Code as defined in and * are subject to the Apple Public Source License Version 1.1 (the * "License"). You may not use this file except in compliance with the * License. Please obtain a copy of the License at * http://www.apple.com/publicsource and read it before using this file. - * + * * This Original Code and all software distributed under the License are * distributed on an "AS IS" basis, WITHOUT WARRANTY OF ANY KIND, EITHER * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES, @@ -16,11 +16,10 @@ * FITNESS FOR A PARTICULAR PURPOSE OR NON-INFRINGEMENT. Please see the * License for the specific language governing rights and limitations * under the License. - * + * * @APPLE_OSREFERENCE_LICENSE_HEADER_END@ */ - #include #include @@ -30,16 +29,21 @@ #include #include #include +#include +#include #include #include #include -#define HZ 100 #include #include #include +#include #include +#include +#include + #if defined(__i386__) || defined(__x86_64__) #include #include @@ -55,12 +59,14 @@ #include #include #include +#include #include #include +#include +#include #include #include -#include #include #include @@ -73,6 +79,7 @@ #include #include +#include /* * IOP(s) @@ -110,37 +117,180 @@ typedef struct kd_iop { static kd_iop_t* kd_iops = NULL; -/* XXX should have prototypes, but Mach does not provide one */ +/* + * Typefilter(s) + * + * A typefilter is a 8KB bitmap that is used to selectively filter events + * being recorded. It is able to individually address every class & subclass. + * + * There is a shared typefilter in the kernel which is lazily allocated. Once + * allocated, the shared typefilter is never deallocated. The shared typefilter + * is also mapped on demand into userspace processes that invoke kdebug_trace + * API from Libsyscall. When mapped into a userspace process, the memory is + * read only, and does not have a fixed address. + * + * It is a requirement that the kernel's shared typefilter always pass DBG_TRACE + * events. This is enforced automatically, by having the needed bits set any + * time the shared typefilter is mutated. + */ + +typedef uint8_t* typefilter_t; + +static typefilter_t kdbg_typefilter; +static mach_port_t kdbg_typefilter_memory_entry; + +/* + * There are 3 combinations of page sizes: + * + * 4KB / 4KB + * 4KB / 16KB + * 16KB / 16KB + * + * The typefilter is exactly 8KB. In the first two scenarios, we would like + * to use 2 pages exactly; in the third scenario we must make certain that + * a full page is allocated so we do not inadvertantly share 8KB of random + * data to userspace. The round_page_32 macro rounds to kernel page size. + */ +#define TYPEFILTER_ALLOC_SIZE MAX(round_page_32(KDBG_TYPEFILTER_BITMAP_SIZE), KDBG_TYPEFILTER_BITMAP_SIZE) + +static typefilter_t typefilter_create(void) +{ + typefilter_t tf; + if (KERN_SUCCESS == kmem_alloc(kernel_map, (vm_offset_t*)&tf, TYPEFILTER_ALLOC_SIZE, VM_KERN_MEMORY_DIAG)) { + memset(&tf[KDBG_TYPEFILTER_BITMAP_SIZE], 0, TYPEFILTER_ALLOC_SIZE - KDBG_TYPEFILTER_BITMAP_SIZE); + return tf; + } + return NULL; +} + +static void typefilter_deallocate(typefilter_t tf) +{ + assert(tf); + assert(tf != kdbg_typefilter); + kmem_free(kernel_map, (vm_offset_t)tf, TYPEFILTER_ALLOC_SIZE); +} + +static void typefilter_copy(typefilter_t dst, typefilter_t src) +{ + assert(src); + assert(dst); + memcpy(dst, src, KDBG_TYPEFILTER_BITMAP_SIZE); +} + +static void typefilter_reject_all(typefilter_t tf) +{ + assert(tf); + memset(tf, 0, KDBG_TYPEFILTER_BITMAP_SIZE); +} + +static void typefilter_allow_class(typefilter_t tf, uint8_t class) +{ + assert(tf); + const uint32_t BYTES_PER_CLASS = 256 / 8; // 256 subclasses, 1 bit each + memset(&tf[class * BYTES_PER_CLASS], 0xFF, BYTES_PER_CLASS); +} + +static void typefilter_allow_csc(typefilter_t tf, uint16_t csc) +{ + assert(tf); + setbit(tf, csc); +} + +static boolean_t typefilter_is_debugid_allowed(typefilter_t tf, uint32_t id) +{ + assert(tf); + return isset(tf, KDBG_EXTRACT_CSC(id)); +} + +static mach_port_t typefilter_create_memory_entry(typefilter_t tf) +{ + assert(tf); + + mach_port_t memory_entry = MACH_PORT_NULL; + memory_object_size_t size = TYPEFILTER_ALLOC_SIZE; + + mach_make_memory_entry_64(kernel_map, + &size, + (memory_object_offset_t)tf, + VM_PROT_READ, + &memory_entry, + MACH_PORT_NULL); + + return memory_entry; +} + +static int kdbg_copyin_typefilter(user_addr_t addr, size_t size); +static void kdbg_enable_typefilter(void); +static void kdbg_disable_typefilter(void); + +/* + * External prototypes + */ + void task_act_iterate_wth_args(task_t, void(*)(thread_t, void *), void *); int cpu_number(void); /* XXX include path broken */ -void commpage_update_kdebug_enable(void); /* XXX sign */ +void commpage_update_kdebug_state(void); /* XXX sign */ + +extern int log_leaks; +extern boolean_t kdebug_serial; + +#if KDEBUG_MOJO_TRACE +#include +static void kdebug_serial_print( /* forward */ + uint32_t, uint32_t, uint64_t, + uintptr_t, uintptr_t, uintptr_t, uintptr_t, uintptr_t); +#endif -/* XXX should probably be static, but it's debugging code... */ -int kdbg_read(user_addr_t, size_t *, vnode_t, vfs_context_t); -void kdbg_control_chud(int, void *); int kdbg_control(int *, u_int, user_addr_t, size_t *); -int kdbg_readcpumap(user_addr_t, size_t *); -int kdbg_readcurcpumap(user_addr_t, size_t *); -int kdbg_readthrmap(user_addr_t, size_t *, vnode_t, vfs_context_t); -int kdbg_readcurthrmap(user_addr_t, size_t *); -int kdbg_getreg(kd_regtype *); -int kdbg_setreg(kd_regtype *); -int kdbg_setrtcdec(kd_regtype *); -int kdbg_setpidex(kd_regtype *); -int kdbg_setpid(kd_regtype *); -void kdbg_thrmap_init(void); -int kdbg_reinit(boolean_t); -int kdbg_bootstrap(boolean_t); - -int kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, uint8_t** cpumap, uint32_t* cpumap_size); -kd_threadmap* kdbg_thrmap_init_internal(unsigned int count, unsigned int *mapsize, unsigned int *mapcount); - -static int kdbg_enable_typefilter(void); -static int kdbg_disable_typefilter(void); + +static int kdbg_read(user_addr_t, size_t *, vnode_t, vfs_context_t, uint32_t); +static int kdbg_readcpumap(user_addr_t, size_t *); +static int kdbg_readthrmap_v3(user_addr_t, size_t, int); +static int kdbg_readcurthrmap(user_addr_t, size_t *); +static int kdbg_setreg(kd_regtype *); +static int kdbg_setpidex(kd_regtype *); +static int kdbg_setpid(kd_regtype *); +static void kdbg_thrmap_init(void); +static int kdbg_reinit(boolean_t); +static int kdbg_bootstrap(boolean_t); +static int kdbg_test(void); + +static int kdbg_write_v1_header(boolean_t write_thread_map, vnode_t vp, vfs_context_t ctx); +static int kdbg_write_thread_map(vnode_t vp, vfs_context_t ctx); +static int kdbg_copyout_thread_map(user_addr_t buffer, size_t *buffer_size); +static void kdbg_clear_thread_map(void); + +static boolean_t kdbg_wait(uint64_t timeout_ms, boolean_t locked_wait); +static void kdbg_wakeup(void); + +int kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, + uint8_t** cpumap, uint32_t* cpumap_size); + +static kd_threadmap *kdbg_thrmap_init_internal(unsigned int count, + unsigned int *mapsize, + unsigned int *mapcount); + +static boolean_t kdebug_current_proc_enabled(uint32_t debugid); +boolean_t kdebug_debugid_enabled(uint32_t debugid); +static errno_t kdebug_check_trace_string(uint32_t debugid, uint64_t str_id); + +int kdbg_write_v3_header(user_addr_t, size_t *, int); +int kdbg_write_v3_chunk_header(user_addr_t buffer, uint32_t tag, + uint32_t sub_tag, uint64_t length, + vnode_t vp, vfs_context_t ctx); + +user_addr_t kdbg_write_v3_event_chunk_header(user_addr_t buffer, uint32_t tag, + uint64_t length, vnode_t vp, + vfs_context_t ctx); + +// Helper functions static int create_buffers(boolean_t); static void delete_buffers(void); +extern int tasks_count; +extern int threads_count; +extern char *proc_best_name(proc_t p); extern void IOSleep(int); /* trace enable status */ @@ -152,10 +302,8 @@ static kd_buf kd_early_buffer[KD_EARLY_BUFFER_MAX]; static int kd_early_index = 0; static boolean_t kd_early_overflow = FALSE; -#define SLOW_NOLOG 0x01 -#define SLOW_CHECKS 0x02 -#define SLOW_ENTROPY 0x04 /* Obsolescent */ -#define SLOW_CHUD 0x08 +#define SLOW_NOLOG 0x01 +#define SLOW_CHECKS 0x02 #define EVENTS_PER_STORAGE_UNIT 2048 #define MIN_STORAGE_UNITS_PER_CPU 4 @@ -206,6 +354,11 @@ struct kd_bufinfo { uint32_t num_bufs; } __attribute__(( aligned(MAX_CPU_CACHE_LINE_SIZE) )); + +/* + * In principle, this control block can be shared in DRAM with other + * coprocessors and runtimes, for configuring what tracing is enabled. + */ struct kd_ctrl_page_t { union kds_ptr kds_free_list; uint32_t enabled :1; @@ -213,6 +366,7 @@ struct kd_ctrl_page_t { int kds_inuse_count; uint32_t kdebug_flags; uint32_t kdebug_slowcheck; + uint64_t oldest_time; /* * The number of kd_bufinfo structs allocated may not match the current * number of active cpus. We capture the iops list head at initialization @@ -222,7 +376,11 @@ struct kd_ctrl_page_t { */ kd_iop_t* kdebug_iops; uint32_t kdebug_cpus; -} kd_ctrl_page = { .kds_free_list = {.raw = KDS_PTR_NULL}, .kdebug_slowcheck = SLOW_NOLOG }; +} kd_ctrl_page = { + .kds_free_list = {.raw = KDS_PTR_NULL}, + .kdebug_slowcheck = SLOW_NOLOG, + .oldest_time = 0 +}; #pragma pack() @@ -230,11 +388,11 @@ struct kd_bufinfo *kdbip = NULL; #define KDCOPYBUF_COUNT 8192 #define KDCOPYBUF_SIZE (KDCOPYBUF_COUNT * sizeof(kd_buf)) -kd_buf *kdcopybuf = NULL; -boolean_t kdlog_bg_trace = FALSE; -boolean_t kdlog_bg_trace_running = FALSE; -unsigned int bg_nkdbufs = 0; +#define PAGE_4KB 4096 +#define PAGE_16KB 16384 + +kd_buf *kdcopybuf = NULL; unsigned int nkdbufs = 0; unsigned int kdlog_beg=0; @@ -246,30 +404,6 @@ unsigned int kdlog_value4=0; static lck_spin_t * kdw_spin_lock; static lck_spin_t * kds_spin_lock; -static lck_mtx_t * kd_trace_mtx_sysctl; -static lck_grp_t * kd_trace_mtx_sysctl_grp; -static lck_attr_t * kd_trace_mtx_sysctl_attr; -static lck_grp_attr_t *kd_trace_mtx_sysctl_grp_attr; - -static lck_grp_t *stackshot_subsys_lck_grp; -static lck_grp_attr_t *stackshot_subsys_lck_grp_attr; -static lck_attr_t *stackshot_subsys_lck_attr; -static lck_mtx_t stackshot_subsys_mutex; - -void *stackshot_snapbuf = NULL; - -int -stack_snapshot2(pid_t pid, user_addr_t tracebuf, uint32_t tracebuf_size, uint32_t flags, uint32_t dispatch_offset, int32_t *retval); - -int -stack_snapshot_from_kernel(pid_t pid, void *buf, uint32_t size, uint32_t flags, unsigned *bytesTraced); -extern void -kdp_snapshot_preflight(int pid, void *tracebuf, uint32_t tracebuf_size, uint32_t flags, uint32_t dispatch_offset); - -extern int -kdp_stack_snapshot_geterror(void); -extern unsigned int -kdp_stack_snapshot_bytes_traced(void); kd_threadmap *kd_mapptr = 0; unsigned int kd_mapsize = 0; @@ -280,28 +414,27 @@ int RAW_file_written = 0; #define RAW_FLUSH_SIZE (2 * 1024 * 1024) -pid_t global_state_pid = -1; /* Used to control exclusive use of kd_buffer */ - -#define DBG_FUNC_MASK 0xfffffffc +/* + * A globally increasing counter for identifying strings in trace. Starts at + * 1 because 0 is a reserved return value. + */ +__attribute__((aligned(MAX_CPU_CACHE_LINE_SIZE))) +static uint64_t g_curr_str_id = 1; -/* TODO: move to kdebug.h */ -#define CLASS_MASK 0xff000000 -#define CLASS_OFFSET 24 -#define SUBCLASS_MASK 0x00ff0000 -#define SUBCLASS_OFFSET 16 -#define CSC_MASK 0xffff0000 /* class and subclass mask */ -#define CSC_OFFSET SUBCLASS_OFFSET +#define STR_ID_SIG_OFFSET (48) +#define STR_ID_MASK ((1ULL << STR_ID_SIG_OFFSET) - 1) +#define STR_ID_SIG_MASK (~STR_ID_MASK) -#define EXTRACT_CLASS(debugid) ( (uint8_t) ( ((debugid) & CLASS_MASK ) >> CLASS_OFFSET ) ) -#define EXTRACT_SUBCLASS(debugid) ( (uint8_t) ( ((debugid) & SUBCLASS_MASK) >> SUBCLASS_OFFSET ) ) -#define EXTRACT_CSC(debugid) ( (uint16_t)( ((debugid) & CSC_MASK ) >> CSC_OFFSET ) ) +/* + * A bit pattern for identifying string IDs generated by + * kdebug_trace_string(2). + */ +static uint64_t g_str_id_signature = (0x70acULL << STR_ID_SIG_OFFSET); #define INTERRUPT 0x01050000 #define MACH_vmfault 0x01300008 #define BSC_SysCall 0x040c0000 #define MACH_SysCall 0x010c0000 -#define DBG_SCALL_MASK 0xffff0000 - /* task to string structure */ struct tts @@ -323,48 +456,10 @@ struct krt typedef struct krt krt_t; -/* This is for the CHUD toolkit call */ -typedef void (*kd_chudhook_fn) (uint32_t debugid, uintptr_t arg1, - uintptr_t arg2, uintptr_t arg3, - uintptr_t arg4, uintptr_t arg5); - -volatile kd_chudhook_fn kdebug_chudhook = 0; /* pointer to CHUD toolkit function */ - -__private_extern__ void stackshot_lock_init( void ); - -static uint8_t *type_filter_bitmap; - -/* - * This allows kperf to swap out the global state pid when kperf ownership is - * passed from one process to another. It checks the old global state pid so - * that kperf can't accidentally steal control of trace when a non-kperf trace user has - * control of trace. - */ -void -kdbg_swap_global_state_pid(pid_t old_pid, pid_t new_pid); - -void -kdbg_swap_global_state_pid(pid_t old_pid, pid_t new_pid) -{ - if (!(kd_ctrl_page.kdebug_flags & KDBG_LOCKINIT)) - return; - - lck_mtx_lock(kd_trace_mtx_sysctl); - - if (old_pid == global_state_pid) - global_state_pid = new_pid; - - lck_mtx_unlock(kd_trace_mtx_sysctl); -} - static uint32_t kdbg_cpu_count(boolean_t early_trace) { if (early_trace) { - /* - * we've started tracing before the IOKit has even - * started running... just use the static max value - */ return max_ncpus; } @@ -392,17 +487,16 @@ kdbg_set_tracing_enabled(boolean_t enabled, uint32_t trace_type) { int s = ml_set_interrupts_enabled(FALSE); lck_spin_lock(kds_spin_lock); - if (enabled) { kdebug_enable |= trace_type; kd_ctrl_page.kdebug_slowcheck &= ~SLOW_NOLOG; kd_ctrl_page.enabled = 1; - commpage_update_kdebug_enable(); + commpage_update_kdebug_state(); } else { kdebug_enable &= ~(KDEBUG_ENABLE_TRACE|KDEBUG_ENABLE_PPT); kd_ctrl_page.kdebug_slowcheck |= SLOW_NOLOG; kd_ctrl_page.enabled = 0; - commpage_update_kdebug_enable(); + commpage_update_kdebug_state(); } lck_spin_unlock(kds_spin_lock); ml_set_interrupts_enabled(s); @@ -438,20 +532,27 @@ kdbg_set_flags(int slowflag, int enableflag, boolean_t enabled) ml_set_interrupts_enabled(s); } -void +/* + * Disable wrapping and return true if trace wrapped, false otherwise. + */ +boolean_t disable_wrap(uint32_t *old_slowcheck, uint32_t *old_flags) { + boolean_t wrapped; int s = ml_set_interrupts_enabled(FALSE); lck_spin_lock(kds_spin_lock); *old_slowcheck = kd_ctrl_page.kdebug_slowcheck; *old_flags = kd_ctrl_page.kdebug_flags; + wrapped = kd_ctrl_page.kdebug_flags & KDBG_WRAPPED; kd_ctrl_page.kdebug_flags &= ~KDBG_WRAPPED; kd_ctrl_page.kdebug_flags |= KDBG_NOWRAP; lck_spin_unlock(kds_spin_lock); ml_set_interrupts_enabled(s); + + return wrapped; } void @@ -475,11 +576,11 @@ enable_wrap(uint32_t old_slowcheck, boolean_t lostevents) static int create_buffers(boolean_t early_trace) { - int i; - int p_buffer_size; - int f_buffer_size; - int f_buffers; - int error = 0; + int i; + int p_buffer_size; + int f_buffer_size; + int f_buffers; + int error = 0; /* * For the duration of this allocation, trace code will only reference @@ -499,7 +600,7 @@ create_buffers(boolean_t early_trace) kd_ctrl_page.kdebug_cpus = kd_ctrl_page.kdebug_iops ? kd_ctrl_page.kdebug_iops->cpu_id + 1 : kdbg_cpu_count(early_trace); - if (kmem_alloc(kernel_map, (vm_offset_t *)&kdbip, sizeof(struct kd_bufinfo) * kd_ctrl_page.kdebug_cpus) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&kdbip, sizeof(struct kd_bufinfo) * kd_ctrl_page.kdebug_cpus, VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { error = ENOSPC; goto out; } @@ -523,19 +624,19 @@ create_buffers(boolean_t early_trace) kd_bufs = NULL; if (kdcopybuf == 0) { - if (kmem_alloc(kernel_map, (vm_offset_t *)&kdcopybuf, (vm_size_t)KDCOPYBUF_SIZE) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&kdcopybuf, (vm_size_t)KDCOPYBUF_SIZE, VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { error = ENOSPC; goto out; } } - if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs, (vm_size_t)(n_storage_buffers * sizeof(struct kd_storage_buffers))) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs, (vm_size_t)(n_storage_buffers * sizeof(struct kd_storage_buffers)), VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { error = ENOSPC; goto out; } bzero(kd_bufs, n_storage_buffers * sizeof(struct kd_storage_buffers)); for (i = 0; i < f_buffers; i++) { - if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs[i].kdsb_addr, (vm_size_t)f_buffer_size) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs[i].kdsb_addr, (vm_size_t)f_buffer_size, VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { error = ENOSPC; goto out; } @@ -544,7 +645,7 @@ create_buffers(boolean_t early_trace) kd_bufs[i].kdsb_size = f_buffer_size; } if (p_buffer_size) { - if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs[i].kdsb_addr, (vm_size_t)p_buffer_size) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&kd_bufs[i].kdsb_addr, (vm_size_t)p_buffer_size, VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { error = ENOSPC; goto out; } @@ -667,13 +768,13 @@ release_storage_unit(int cpu, uint32_t kdsp_raw) boolean_t allocate_storage_unit(int cpu) { - union kds_ptr kdsp; - struct kd_storage *kdsp_actual, *kdsp_next_actual; - struct kd_bufinfo *kdbp, *kdbp_vict, *kdbp_try; - uint64_t oldest_ts, ts; - boolean_t retval = TRUE; - int s = 0; - + union kds_ptr kdsp; + struct kd_storage *kdsp_actual, *kdsp_next_actual; + struct kd_bufinfo *kdbp, *kdbp_vict, *kdbp_try; + uint64_t oldest_ts, ts; + boolean_t retval = TRUE; + int s = 0; + s = ml_set_interrupts_enabled(FALSE); lck_spin_lock(kds_spin_lock); @@ -700,7 +801,7 @@ allocate_storage_unit(int cpu) goto out; } kdbp_vict = NULL; - oldest_ts = (uint64_t)-1; + oldest_ts = UINT64_MAX; for (kdbp_try = &kdbip[0]; kdbp_try < &kdbip[kd_ctrl_page.kdebug_cpus]; kdbp_try++) { @@ -722,14 +823,17 @@ allocate_storage_unit(int cpu) */ continue; } - ts = kdbg_get_timestamp(&kdsp_actual->kds_records[0]); + /* + * When wrapping, steal the storage unit with the + * earliest timestamp on its last event, instead of the + * earliest timestamp on the first event. This allows a + * storage unit with more recent events to be preserved, + * even if the storage unit contains events that are + * older than those found in other CPUs. + */ + ts = kdbg_get_timestamp(&kdsp_actual->kds_records[EVENTS_PER_STORAGE_UNIT - 1]); if (ts < oldest_ts) { - /* - * when 'wrapping', we want to steal the - * storage unit that has the 'earliest' time - * associated with it (first event time) - */ oldest_ts = ts; kdbp_vict = kdbp_try; } @@ -737,7 +841,7 @@ allocate_storage_unit(int cpu) if (kdbp_vict == NULL) { kdebug_enable = 0; kd_ctrl_page.enabled = 0; - commpage_update_kdebug_enable(); + commpage_update_kdebug_state(); retval = FALSE; goto out; } @@ -751,6 +855,7 @@ allocate_storage_unit(int cpu) } else kdbp_vict->kd_lostevents = TRUE; + kd_ctrl_page.oldest_time = oldest_ts; kd_ctrl_page.kdebug_flags |= KDBG_WRAPPED; } kdsp_actual->kds_timestamp = mach_absolute_time(); @@ -778,7 +883,7 @@ int kernel_debug_register_callback(kd_callback_t callback) { kd_iop_t* iop; - if (kmem_alloc(kernel_map, (vm_offset_t *)&iop, sizeof(kd_iop_t)) == KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t *)&iop, sizeof(kd_iop_t), VM_KERN_MEMORY_DIAG) == KERN_SUCCESS) { memcpy(&iop->callback, &callback, sizeof(kd_callback_t)); /* @@ -853,7 +958,7 @@ kernel_debug_enter( goto out1; if (kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) { - if (isset(type_filter_bitmap, EXTRACT_CSC(debugid))) + if (typefilter_is_debugid_allowed(kdbg_typefilter, debugid)) goto record_event; goto out1; } @@ -863,14 +968,20 @@ kernel_debug_enter( goto out1; } else if (kd_ctrl_page.kdebug_flags & KDBG_VALCHECK) { - if ((debugid & DBG_FUNC_MASK) != kdlog_value1 && - (debugid & DBG_FUNC_MASK) != kdlog_value2 && - (debugid & DBG_FUNC_MASK) != kdlog_value3 && - (debugid & DBG_FUNC_MASK) != kdlog_value4) + if ((debugid & KDBG_EVENTID_MASK) != kdlog_value1 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value2 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value3 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value4) goto out1; } } - + + if (kd_ctrl_page.kdebug_flags & KDBG_WRAPPED) { + if (timestamp < kd_ctrl_page.oldest_time) { + goto out1; + } + } + record_event: disable_preemption(); @@ -881,6 +992,12 @@ record_event: kdbp = &kdbip[coreid]; timestamp &= KDBG_TIMESTAMP_MASK; +#if KDEBUG_MOJO_TRACE + if (kdebug_enable & KDEBUG_ENABLE_SERIAL) + kdebug_serial_print(coreid, debugid, timestamp, + arg1, arg2, arg3, arg4, threadid); +#endif + retry_q: kds_raw = kdbp->kd_list_tail; @@ -923,78 +1040,36 @@ out: enable_preemption(); out1: if ((kds_waiter && kd_ctrl_page.kds_inuse_count >= n_storage_threshold)) { - boolean_t need_kds_wakeup = FALSE; - int s; - - /* - * try to take the lock here to synchronize with the - * waiter entering the blocked state... use the try - * mode to prevent deadlocks caused by re-entering this - * routine due to various trace points triggered in the - * lck_spin_sleep_xxxx routines used to actually enter - * our wait condition... no problem if we fail, - * there will be lots of additional events coming in that - * will eventually succeed in grabbing this lock - */ - s = ml_set_interrupts_enabled(FALSE); - - if (lck_spin_try_lock(kdw_spin_lock)) { - - if (kds_waiter && kd_ctrl_page.kds_inuse_count >= n_storage_threshold) { - kds_waiter = 0; - need_kds_wakeup = TRUE; - } - lck_spin_unlock(kdw_spin_lock); - - ml_set_interrupts_enabled(s); - - if (need_kds_wakeup == TRUE) - wakeup(&kds_waiter); - } + kdbg_wakeup(); } } - - static void kernel_debug_internal( - uint32_t debugid, - uintptr_t arg1, - uintptr_t arg2, - uintptr_t arg3, - uintptr_t arg4, - uintptr_t arg5) + boolean_t only_filter, + uint32_t debugid, + uintptr_t arg1, + uintptr_t arg2, + uintptr_t arg3, + uintptr_t arg4, + uintptr_t arg5) { - struct proc *curproc; + struct proc *curproc; uint64_t now; uint32_t bindx; - boolean_t s; kd_buf *kd; int cpu; struct kd_bufinfo *kdbp; struct kd_storage *kdsp_actual; union kds_ptr kds_raw; - - if (kd_ctrl_page.kdebug_slowcheck) { - - if (kdebug_enable & KDEBUG_ENABLE_CHUD) { - kd_chudhook_fn chudhook; - /* - * Mask interrupts to minimize the interval across - * which the driver providing the hook could be - * unloaded. - */ - s = ml_set_interrupts_enabled(FALSE); - chudhook = kdebug_chudhook; - if (chudhook) - chudhook(debugid, arg1, arg2, arg3, arg4, arg5); - ml_set_interrupts_enabled(s); - } - if ( (kd_ctrl_page.kdebug_slowcheck & SLOW_NOLOG) || !(kdebug_enable & (KDEBUG_ENABLE_TRACE|KDEBUG_ENABLE_PPT))) + if ((kd_ctrl_page.kdebug_slowcheck & SLOW_NOLOG) || + !(kdebug_enable & (KDEBUG_ENABLE_TRACE | KDEBUG_ENABLE_PPT))) + { goto out1; - + } + if ( !ml_at_interrupt_context()) { if (kd_ctrl_page.kdebug_flags & KDBG_PIDCHECK) { /* @@ -1021,17 +1096,16 @@ kernel_debug_internal( } if (kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) { - /* Always record trace system info */ - if (EXTRACT_CLASS(debugid) == DBG_TRACE) + if (typefilter_is_debugid_allowed(kdbg_typefilter, debugid)) goto record_event; - if (isset(type_filter_bitmap, EXTRACT_CSC(debugid))) - goto record_event; + goto out1; + } else if (only_filter == TRUE) { goto out1; } else if (kd_ctrl_page.kdebug_flags & KDBG_RANGECHECK) { /* Always record trace system info */ - if (EXTRACT_CLASS(debugid) == DBG_TRACE) + if (KDBG_EXTRACT_CLASS(debugid) == DBG_TRACE) goto record_event; if (debugid < kdlog_beg || debugid > kdlog_end) @@ -1039,16 +1113,19 @@ kernel_debug_internal( } else if (kd_ctrl_page.kdebug_flags & KDBG_VALCHECK) { /* Always record trace system info */ - if (EXTRACT_CLASS(debugid) == DBG_TRACE) + if (KDBG_EXTRACT_CLASS(debugid) == DBG_TRACE) goto record_event; - if ((debugid & DBG_FUNC_MASK) != kdlog_value1 && - (debugid & DBG_FUNC_MASK) != kdlog_value2 && - (debugid & DBG_FUNC_MASK) != kdlog_value3 && - (debugid & DBG_FUNC_MASK) != kdlog_value4) + if ((debugid & KDBG_EVENTID_MASK) != kdlog_value1 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value2 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value3 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value4) goto out1; } + } else if (only_filter == TRUE) { + goto out1; } + record_event: disable_preemption(); @@ -1057,6 +1134,14 @@ record_event: cpu = cpu_number(); kdbp = &kdbip[cpu]; + +#if KDEBUG_MOJO_TRACE + if (kdebug_enable & KDEBUG_ENABLE_SERIAL) + kdebug_serial_print(cpu, debugid, + mach_absolute_time() & KDBG_TIMESTAMP_MASK, + arg1, arg2, arg3, arg4, arg5); +#endif + retry_q: kds_raw = kdbp->kd_list_tail; @@ -1089,49 +1174,27 @@ retry_q: kd->arg3 = arg3; kd->arg4 = arg4; kd->arg5 = arg5; - + kdbg_set_timestamp_and_cpu(kd, now, cpu); OSAddAtomic(1, &kdsp_actual->kds_bufcnt); + +#if KPERF + kperf_kdebug_callback(debugid, __builtin_frame_address(0)); +#endif out: enable_preemption(); out1: if (kds_waiter && kd_ctrl_page.kds_inuse_count >= n_storage_threshold) { uint32_t etype; uint32_t stype; - - etype = debugid & DBG_FUNC_MASK; - stype = debugid & DBG_SCALL_MASK; + + etype = debugid & KDBG_EVENTID_MASK; + stype = debugid & KDBG_CSC_MASK; if (etype == INTERRUPT || etype == MACH_vmfault || stype == BSC_SysCall || stype == MACH_SysCall) { - - boolean_t need_kds_wakeup = FALSE; - - /* - * try to take the lock here to synchronize with the - * waiter entering the blocked state... use the try - * mode to prevent deadlocks caused by re-entering this - * routine due to various trace points triggered in the - * lck_spin_sleep_xxxx routines used to actually enter - * one of our 2 wait conditions... no problem if we fail, - * there will be lots of additional events coming in that - * will eventually succeed in grabbing this lock - */ - s = ml_set_interrupts_enabled(FALSE); - - if (lck_spin_try_lock(kdw_spin_lock)) { - - if (kds_waiter && kd_ctrl_page.kds_inuse_count >= n_storage_threshold) { - kds_waiter = 0; - need_kds_wakeup = TRUE; - } - lck_spin_unlock(kdw_spin_lock); - } - ml_set_interrupts_enabled(s); - - if (need_kds_wakeup == TRUE) - wakeup(&kds_waiter); + kdbg_wakeup(); } } } @@ -1145,7 +1208,8 @@ kernel_debug( uintptr_t arg4, __unused uintptr_t arg5) { - kernel_debug_internal(debugid, arg1, arg2, arg3, arg4, (uintptr_t)thread_tid(current_thread())); + kernel_debug_internal(FALSE, debugid, arg1, arg2, arg3, arg4, + (uintptr_t)thread_tid(current_thread())); } void @@ -1157,21 +1221,72 @@ kernel_debug1( uintptr_t arg4, uintptr_t arg5) { - kernel_debug_internal(debugid, arg1, arg2, arg3, arg4, arg5); + kernel_debug_internal(FALSE, debugid, arg1, arg2, arg3, arg4, arg5); +} + +void +kernel_debug_filtered( + uint32_t debugid, + uintptr_t arg1, + uintptr_t arg2, + uintptr_t arg3, + uintptr_t arg4) +{ + kernel_debug_internal(TRUE, debugid, arg1, arg2, arg3, arg4, + (uintptr_t)thread_tid(current_thread())); } void -kernel_debug_string(const char *message) +kernel_debug_string_early(const char *message) { uintptr_t arg[4] = {0, 0, 0, 0}; /* Stuff the message string in the args and log it. */ - strncpy((char *)arg, message, MIN(sizeof(arg), strlen(message))); + strncpy((char *)arg, message, MIN(sizeof(arg), strlen(message))); KERNEL_DEBUG_EARLY( - (TRACEDBG_CODE(DBG_TRACE_INFO, 4)) | DBG_FUNC_NONE, + TRACE_INFO_STRING, arg[0], arg[1], arg[2], arg[3]); } +#define SIMPLE_STR_LEN (64) +static_assert(SIMPLE_STR_LEN % sizeof(uintptr_t) == 0); + +void +kernel_debug_string_simple(uint32_t eventid, const char *str) +{ + /* array of uintptr_ts simplifies emitting the string as arguments */ + uintptr_t str_buf[(SIMPLE_STR_LEN / sizeof(uintptr_t)) + 1] = { 0 }; + size_t len = strlcpy((char *)str_buf, str, SIMPLE_STR_LEN + 1); + + uintptr_t thread_id = (uintptr_t)thread_tid(current_thread()); + uint32_t debugid = eventid | DBG_FUNC_START; + + /* string can fit in a single tracepoint */ + if (len <= (4 * sizeof(uintptr_t))) { + debugid |= DBG_FUNC_END; + } + + kernel_debug_internal(FALSE, debugid, str_buf[0], + str_buf[1], + str_buf[2], + str_buf[3], thread_id); + + debugid &= KDBG_EVENTID_MASK; + int i = 4; + size_t written = 4 * sizeof(uintptr_t); + + for (; written < len; i += 4, written += 4 * sizeof(uintptr_t)) { + /* if this is the last tracepoint to be emitted */ + if ((written + (4 * sizeof(uintptr_t))) >= len) { + debugid |= DBG_FUNC_END; + } + kernel_debug_internal(FALSE, debugid, str_buf[i], + str_buf[i + 1], + str_buf[i + 2], + str_buf[i + 3], thread_id); + } +} + extern int master_cpu; /* MACH_KERNEL_PRIVATE */ /* * Used prior to start_kern_tracing() being called. @@ -1186,8 +1301,10 @@ kernel_debug_early( uintptr_t arg4) { /* If tracing is already initialized, use it */ - if (nkdbufs) + if (nkdbufs) { KERNEL_DEBUG_CONSTANT(debugid, arg1, arg2, arg3, arg4, 0); + return; + } /* Do nothing if the buffer is full or we're not on the boot cpu */ kd_early_overflow = kd_early_index >= KD_EARLY_BUFFER_MAX; @@ -1206,7 +1323,7 @@ kernel_debug_early( } /* - * Transfer the contents of the temporary buffer into the trace buffers. + * Transfen the contents of the temporary buffer into the trace buffers. * Precede that by logging the rebase time (offset) - the TSC-based time (in ns) * when mach_absolute_time is set to 0. */ @@ -1221,7 +1338,7 @@ kernel_debug_early_end(void) /* Fake sentinel marking the start of kernel time relative to TSC */ kernel_debug_enter( 0, - (TRACEDBG_CODE(DBG_TRACE_INFO, 1)) | DBG_FUNC_NONE, + TRACE_TIMESTAMPS, 0, (uint32_t)(tsc_rebase_abs_time >> 32), (uint32_t)tsc_rebase_abs_time, @@ -1243,10 +1360,112 @@ kernel_debug_early_end(void) /* Cut events-lost event on overflow */ if (kd_early_overflow) KERNEL_DEBUG_CONSTANT( - TRACEDBG_CODE(DBG_TRACE_INFO, 2), 0, 0, 0, 0, 0); + TRACE_LOST_EVENTS, 0, 0, 0, 0, 0); /* This trace marks the start of kernel tracing */ - kernel_debug_string("early trace done"); + kernel_debug_string_early("early trace done"); +} + +void +kernel_debug_disable(void) +{ + if (kdebug_enable) { + kdbg_set_tracing_enabled(FALSE, 0); + } +} + +/* + * Returns non-zero if debugid is in a reserved class. + */ +static int +kdebug_validate_debugid(uint32_t debugid) +{ + uint8_t debugid_class; + + debugid_class = KDBG_EXTRACT_CLASS(debugid); + switch (debugid_class) { + case DBG_TRACE: + return EPERM; + } + + return 0; +} + +/* + * Support syscall SYS_kdebug_typefilter. + */ +int +kdebug_typefilter(__unused struct proc* p, + struct kdebug_typefilter_args* uap, + __unused int *retval) +{ + int ret = KERN_SUCCESS; + + if (uap->addr == USER_ADDR_NULL || + uap->size == USER_ADDR_NULL) { + return EINVAL; + } + + /* + * The atomic load is to close a race window with setting the typefilter + * and memory entry values. A description follows: + * + * Thread 1 (writer) + * + * Allocate Typefilter + * Allocate MemoryEntry + * Write Global MemoryEntry Ptr + * Atomic Store (Release) Global Typefilter Ptr + * + * Thread 2 (reader, AKA us) + * + * if ((Atomic Load (Acquire) Global Typefilter Ptr) == NULL) + * return; + * + * Without the atomic store, it isn't guaranteed that the write of + * Global MemoryEntry Ptr is visible before we can see the write of + * Global Typefilter Ptr. + * + * Without the atomic load, it isn't guaranteed that the loads of + * Global MemoryEntry Ptr aren't speculated. + * + * The global pointers transition from NULL -> valid once and only once, + * and never change after becoming valid. This means that having passed + * the first atomic load test of Global Typefilter Ptr, this function + * can then safely use the remaining global state without atomic checks. + */ + if (!__c11_atomic_load((_Atomic typefilter_t *)&kdbg_typefilter, memory_order_acquire)) { + return EINVAL; + } + + assert(kdbg_typefilter_memory_entry); + + mach_vm_offset_t user_addr = 0; + vm_map_t user_map = current_map(); + + ret = mach_to_bsd_errno( + mach_vm_map(user_map, // target map + &user_addr, // [in, out] target address + TYPEFILTER_ALLOC_SIZE, // initial size + 0, // mask (alignment?) + VM_FLAGS_ANYWHERE, // flags + kdbg_typefilter_memory_entry, // port (memory entry!) + 0, // offset (in memory entry) + FALSE, // should copy + VM_PROT_READ, // cur_prot + VM_PROT_READ, // max_prot + VM_INHERIT_SHARE)); // inherit behavior on fork + + if (ret == KERN_SUCCESS) { + vm_size_t user_ptr_size = vm_map_is_64bit(user_map) ? 8 : 4; + ret = copyout(CAST_DOWN(void *, &user_addr), uap->addr, user_ptr_size ); + + if (ret != KERN_SUCCESS) { + mach_vm_deallocate(user_map, user_addr, TYPEFILTER_ALLOC_SIZE); + } + } + + return ret; } /* @@ -1267,64 +1486,346 @@ kdebug_trace(struct proc *p, struct kdebug_trace_args *uap, int32_t *retval) } /* - * Support syscall SYS_kdebug_trace64. 64-bit args on K32 will get truncated to fit in 32-bit record format. + * Support syscall SYS_kdebug_trace64. 64-bit args on K32 will get truncated + * to fit in 32-bit record format. + * + * It is intentional that error conditions are not checked until kdebug is + * enabled. This is to match the userspace wrapper behavior, which is optimizing + * for non-error case performance. */ int kdebug_trace64(__unused struct proc *p, struct kdebug_trace64_args *uap, __unused int32_t *retval) { - uint8_t code_class; + int err; - /* - * Not all class are supported for injection from userspace, especially ones used by the core - * kernel tracing infrastructure. - */ - code_class = EXTRACT_CLASS(uap->code); + if ( __probable(kdebug_enable == 0) ) + return(0); - switch (code_class) { - case DBG_TRACE: - return EPERM; + if ((err = kdebug_validate_debugid(uap->code)) != 0) { + return err; } - if ( __probable(kdebug_enable == 0) ) - return(0); - - kernel_debug_internal(uap->code, (uintptr_t)uap->arg1, (uintptr_t)uap->arg2, (uintptr_t)uap->arg3, (uintptr_t)uap->arg4, (uintptr_t)thread_tid(current_thread())); + kernel_debug_internal(FALSE, uap->code, + (uintptr_t)uap->arg1, + (uintptr_t)uap->arg2, + (uintptr_t)uap->arg3, + (uintptr_t)uap->arg4, + (uintptr_t)thread_tid(current_thread())); return(0); } -static void -kdbg_lock_init(void) +/* + * Adding enough padding to contain a full tracepoint for the last + * portion of the string greatly simplifies the logic of splitting the + * string between tracepoints. Full tracepoints can be generated using + * the buffer itself, without having to manually add zeros to pad the + * arguments. + */ + +/* 2 string args in first tracepoint and 9 string data tracepoints */ +#define STR_BUF_ARGS (2 + (9 * 4)) +/* times the size of each arg on K64 */ +#define MAX_STR_LEN (STR_BUF_ARGS * sizeof(uint64_t)) +/* on K32, ending straddles a tracepoint, so reserve blanks */ +#define STR_BUF_SIZE (MAX_STR_LEN + (2 * sizeof(uint32_t))) + +/* + * This function does no error checking and assumes that it is called with + * the correct arguments, including that the buffer pointed to by str is at + * least STR_BUF_SIZE bytes. However, str must be aligned to word-size and + * be NUL-terminated. In cases where a string can fit evenly into a final + * tracepoint without its NUL-terminator, this function will not end those + * strings with a NUL in trace. It's up to clients to look at the function + * qualifier for DBG_FUNC_END in this case, to end the string. + */ +static uint64_t +kernel_debug_string_internal(uint32_t debugid, uint64_t str_id, void *vstr, + size_t str_len) { - if (kd_ctrl_page.kdebug_flags & KDBG_LOCKINIT) - return; - - /* - * allocate lock group attribute and group - */ - kd_trace_mtx_sysctl_grp_attr = lck_grp_attr_alloc_init(); - kd_trace_mtx_sysctl_grp = lck_grp_alloc_init("kdebug", kd_trace_mtx_sysctl_grp_attr); - - /* - * allocate the lock attribute - */ - kd_trace_mtx_sysctl_attr = lck_attr_alloc_init(); + /* str must be word-aligned */ + uintptr_t *str = vstr; + size_t written = 0; + uintptr_t thread_id; + int i; + uint32_t trace_debugid = TRACEDBG_CODE(DBG_TRACE_STRING, + TRACE_STRING_GLOBAL); + thread_id = (uintptr_t)thread_tid(current_thread()); - /* - * allocate and initialize mutex's - */ - kd_trace_mtx_sysctl = lck_mtx_alloc_init(kd_trace_mtx_sysctl_grp, kd_trace_mtx_sysctl_attr); - kds_spin_lock = lck_spin_alloc_init(kd_trace_mtx_sysctl_grp, kd_trace_mtx_sysctl_attr); - kdw_spin_lock = lck_spin_alloc_init(kd_trace_mtx_sysctl_grp, kd_trace_mtx_sysctl_attr); + /* if the ID is being invalidated, just emit that */ + if (str_id != 0 && str_len == 0) { + kernel_debug_internal(FALSE, trace_debugid | DBG_FUNC_START | DBG_FUNC_END, + (uintptr_t)debugid, (uintptr_t)str_id, 0, 0, + thread_id); + return str_id; + } - kd_ctrl_page.kdebug_flags |= KDBG_LOCKINIT; + /* generate an ID, if necessary */ + if (str_id == 0) { + str_id = OSIncrementAtomic64((SInt64 *)&g_curr_str_id); + str_id = (str_id & STR_ID_MASK) | g_str_id_signature; + } + + trace_debugid |= DBG_FUNC_START; + /* string can fit in a single tracepoint */ + if (str_len <= (2 * sizeof(uintptr_t))) { + trace_debugid |= DBG_FUNC_END; + } + + kernel_debug_internal(FALSE, trace_debugid, (uintptr_t)debugid, + (uintptr_t)str_id, str[0], + str[1], thread_id); + + trace_debugid &= KDBG_EVENTID_MASK; + i = 2; + written += 2 * sizeof(uintptr_t); + + for (; written < str_len; i += 4, written += 4 * sizeof(uintptr_t)) { + if ((written + (4 * sizeof(uintptr_t))) >= str_len) { + trace_debugid |= DBG_FUNC_END; + } + kernel_debug_internal(FALSE, trace_debugid, str[i], + str[i + 1], + str[i + 2], + str[i + 3], thread_id); + } + + return str_id; +} + +/* + * Returns true if the current process can emit events, and false otherwise. + * Trace system and scheduling events circumvent this check, as do events + * emitted in interrupt context. + */ +static boolean_t +kdebug_current_proc_enabled(uint32_t debugid) +{ + /* can't determine current process in interrupt context */ + if (ml_at_interrupt_context()) { + return TRUE; + } + + /* always emit trace system and scheduling events */ + if ((KDBG_EXTRACT_CLASS(debugid) == DBG_TRACE || + (debugid & KDBG_CSC_MASK) == MACHDBG_CODE(DBG_MACH_SCHED, 0))) + { + return TRUE; + } + + if (kd_ctrl_page.kdebug_flags & KDBG_PIDCHECK) { + proc_t cur_proc = current_proc(); + + /* only the process with the kdebug bit set is allowed */ + if (cur_proc && !(cur_proc->p_kdebug)) { + return FALSE; + } + } else if (kd_ctrl_page.kdebug_flags & KDBG_PIDEXCLUDE) { + proc_t cur_proc = current_proc(); + + /* every process except the one with the kdebug bit set is allowed */ + if (cur_proc && cur_proc->p_kdebug) { + return FALSE; + } + } + + return TRUE; +} + +/* + * Returns false if the debugid is disabled by filters, and true if the + * debugid is allowed to be traced. A debugid may not be traced if the + * typefilter disables its class and subclass, it's outside a range + * check, or if it's not an allowed debugid in a value check. Trace + * system events bypass this check. + */ +boolean_t +kdebug_debugid_enabled(uint32_t debugid) +{ + /* if no filtering is enabled */ + if (!kd_ctrl_page.kdebug_slowcheck) { + return TRUE; + } + + if (kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) { + return typefilter_is_debugid_allowed(kdbg_typefilter, debugid); + } else if (KDBG_EXTRACT_CLASS(debugid) == DBG_TRACE) { + return TRUE; + } + + if (kd_ctrl_page.kdebug_flags & KDBG_RANGECHECK) { + if (debugid < kdlog_beg || debugid > kdlog_end) { + return FALSE; + } + } else if (kd_ctrl_page.kdebug_flags & KDBG_VALCHECK) { + if ((debugid & KDBG_EVENTID_MASK) != kdlog_value1 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value2 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value3 && + (debugid & KDBG_EVENTID_MASK) != kdlog_value4) + { + return FALSE; + } + } + + return TRUE; +} + +/* + * Returns 0 if a string can be traced with these arguments. Returns errno + * value if error occurred. + */ +static errno_t +kdebug_check_trace_string(uint32_t debugid, uint64_t str_id) +{ + /* if there are function qualifiers on the debugid */ + if (debugid & ~KDBG_EVENTID_MASK) { + return EINVAL; + } + + if (kdebug_validate_debugid(debugid)) { + return EPERM; + } + + if (str_id != 0 && (str_id & STR_ID_SIG_MASK) != g_str_id_signature) { + return EINVAL; + } + + return 0; +} + +/* + * Implementation of KPI kernel_debug_string. + */ +int +kernel_debug_string(uint32_t debugid, uint64_t *str_id, const char *str) +{ + /* arguments to tracepoints must be word-aligned */ + __attribute__((aligned(sizeof(uintptr_t)))) char str_buf[STR_BUF_SIZE]; + static_assert(sizeof(str_buf) > MAX_STR_LEN); + vm_size_t len_copied; + int err; + + assert(str_id); + + if (__probable(kdebug_enable == 0)) { + return 0; + } + + if (!kdebug_current_proc_enabled(debugid)) { + return 0; + } + + if (!kdebug_debugid_enabled(debugid)) { + return 0; + } + + if ((err = kdebug_check_trace_string(debugid, *str_id)) != 0) { + return err; + } + + if (str == NULL) { + if (str_id == 0) { + return EINVAL; + } + + *str_id = kernel_debug_string_internal(debugid, *str_id, NULL, 0); + return 0; + } + + memset(str_buf, 0, sizeof(str_buf)); + len_copied = strlcpy(str_buf, str, MAX_STR_LEN + 1); + *str_id = kernel_debug_string_internal(debugid, *str_id, str_buf, + len_copied); + return 0; +} + +/* + * Support syscall kdebug_trace_string. + */ +int +kdebug_trace_string(__unused struct proc *p, + struct kdebug_trace_string_args *uap, + uint64_t *retval) +{ + __attribute__((aligned(sizeof(uintptr_t)))) char str_buf[STR_BUF_SIZE]; + static_assert(sizeof(str_buf) > MAX_STR_LEN); + size_t len_copied; + int err; + + if (__probable(kdebug_enable == 0)) { + return 0; + } + + if (!kdebug_current_proc_enabled(uap->debugid)) { + return 0; + } + + if (!kdebug_debugid_enabled(uap->debugid)) { + return 0; + } + + if ((err = kdebug_check_trace_string(uap->debugid, uap->str_id)) != 0) { + return err; + } + + if (uap->str == USER_ADDR_NULL) { + if (uap->str_id == 0) { + return EINVAL; + } + + *retval = kernel_debug_string_internal(uap->debugid, uap->str_id, + NULL, 0); + return 0; + } + + memset(str_buf, 0, sizeof(str_buf)); + err = copyinstr(uap->str, str_buf, MAX_STR_LEN + 1, &len_copied); + + /* it's alright to truncate the string, so allow ENAMETOOLONG */ + if (err == ENAMETOOLONG) { + str_buf[MAX_STR_LEN] = '\0'; + } else if (err) { + return err; + } + + if (len_copied <= 1) { + return EINVAL; + } + + /* convert back to a length */ + len_copied--; + + *retval = kernel_debug_string_internal(uap->debugid, uap->str_id, str_buf, + len_copied); + return 0; } +static void +kdbg_lock_init(void) +{ + static lck_grp_attr_t *kdebug_lck_grp_attr = NULL; + static lck_grp_t *kdebug_lck_grp = NULL; + static lck_attr_t *kdebug_lck_attr = NULL; + + if (kd_ctrl_page.kdebug_flags & KDBG_LOCKINIT) { + return; + } + + assert(kdebug_lck_grp_attr == NULL); + kdebug_lck_grp_attr = lck_grp_attr_alloc_init(); + kdebug_lck_grp = lck_grp_alloc_init("kdebug", kdebug_lck_grp_attr); + kdebug_lck_attr = lck_attr_alloc_init(); + + kds_spin_lock = lck_spin_alloc_init(kdebug_lck_grp, kdebug_lck_attr); + kdw_spin_lock = lck_spin_alloc_init(kdebug_lck_grp, kdebug_lck_attr); + + kd_ctrl_page.kdebug_flags |= KDBG_LOCKINIT; +} int kdbg_bootstrap(boolean_t early_trace) { - kd_ctrl_page.kdebug_flags &= ~KDBG_WRAPPED; + kd_ctrl_page.kdebug_flags &= ~KDBG_WRAPPED; return (create_buffers(early_trace)); } @@ -1339,7 +1840,7 @@ kdbg_reinit(boolean_t early_trace) * First make sure we're not in * the middle of cutting a trace */ - kdbg_set_tracing_enabled(FALSE, KDEBUG_ENABLE_TRACE); + kernel_debug_disable(); /* * make sure the SLOW_NOLOG is seen @@ -1350,13 +1851,7 @@ kdbg_reinit(boolean_t early_trace) delete_buffers(); - if ((kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) && kd_mapsize && kd_mapptr) { - kmem_free(kernel_map, (vm_offset_t)kd_mapptr, kd_mapsize); - kd_ctrl_page.kdebug_flags &= ~KDBG_MAPINIT; - kd_mapsize = 0; - kd_mapptr = (kd_threadmap *) 0; - kd_mapcount = 0; - } + kdbg_clear_thread_map(); ret = kdbg_bootstrap(early_trace); RAW_file_offset = 0; @@ -1453,7 +1948,6 @@ kdbg_resolve_map(thread_t th_act, void *opaque) * * We may be reporting data from "now", or from the "past". * - * The "now" data would be for something like kdbg_readcurcpumap(). * The "past" data would be for kdbg_readcpumap(). * * If we do not pass both iops and cpu_count, and iops is NULL, this function @@ -1474,9 +1968,10 @@ kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, uint8_t** cpumap, *cpumap_size = bytes_needed; if (*cpumap == NULL) { - if (kmem_alloc(kernel_map, (vm_offset_t*)cpumap, (vm_size_t)*cpumap_size) != KERN_SUCCESS) { + if (kmem_alloc(kernel_map, (vm_offset_t*)cpumap, (vm_size_t)*cpumap_size, VM_KERN_MEMORY_DIAG) != KERN_SUCCESS) { return ENOMEM; } + bzero(*cpumap, *cpumap_size); } else if (bytes_available < bytes_needed) { return EINVAL; } @@ -1492,7 +1987,6 @@ kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, uint8_t** cpumap, while (iops) { cpus[index].cpu_id = iops->cpu_id; cpus[index].flags = KDBG_CPUMAP_IS_IOP; - bzero(cpus[index].name, sizeof(cpus->name)); strlcpy(cpus[index].name, iops->callback.iop_name, sizeof(cpus->name)); iops = iops->next; @@ -1502,7 +1996,6 @@ kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, uint8_t** cpumap, while (index >= 0) { cpus[index].cpu_id = index; cpus[index].flags = 0; - bzero(cpus[index].name, sizeof(cpus->name)); strlcpy(cpus[index].name, "AP", sizeof(cpus->name)); index--; @@ -1514,40 +2007,35 @@ kdbg_cpumap_init_internal(kd_iop_t* iops, uint32_t cpu_count, uint8_t** cpumap, void kdbg_thrmap_init(void) { - if (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + + if (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) { return; + } kd_mapptr = kdbg_thrmap_init_internal(0, &kd_mapsize, &kd_mapcount); - if (kd_mapptr) + if (kd_mapptr) { kd_ctrl_page.kdebug_flags |= KDBG_MAPINIT; + } } - -kd_threadmap* kdbg_thrmap_init_internal(unsigned int count, unsigned int *mapsize, unsigned int *mapcount) +static kd_threadmap * +kdbg_thrmap_init_internal(unsigned int count, unsigned int *mapsize, unsigned int *mapcount) { - kd_threadmap *mapptr; - struct proc *p; - struct krt akrt; - int tts_count; /* number of task-to-string structures */ - struct tts *tts_mapptr; - unsigned int tts_mapsize = 0; - int i; - vm_offset_t kaddr; + kd_threadmap *mapptr; + proc_t p; + struct krt akrt; + int tts_count = 0; /* number of task-to-string structures */ + struct tts *tts_mapptr; + unsigned int tts_mapsize = 0; + vm_offset_t kaddr; - /* - * need to use PROC_SCANPROCLIST with proc_iterate - */ - proc_list_lock(); + assert(mapsize != NULL); + assert(mapcount != NULL); - /* - * Calculate the sizes of map buffers - */ - for (p = allproc.lh_first, *mapcount=0, tts_count=0; p; p = p->p_list.le_next) { - *mapcount += get_task_numacts((task_t)p->task); - tts_count++; - } - proc_list_unlock(); + *mapcount = threads_count; + tts_count = tasks_count; /* * The proc count could change during buffer allocation, @@ -1555,50 +2043,52 @@ kd_threadmap* kdbg_thrmap_init_internal(unsigned int count, unsigned int *mapsiz * buffer sizes. This gives new tasks some chance of * making into the tables. Bump up by 25%. */ - *mapcount += *mapcount/4; - tts_count += tts_count/4; + *mapcount += *mapcount / 4; + tts_count += tts_count / 4; *mapsize = *mapcount * sizeof(kd_threadmap); - if (count && count < *mapcount) - return (0); + if (count && count < *mapcount) { + return 0; + } - if ((kmem_alloc(kernel_map, &kaddr, (vm_size_t)*mapsize) == KERN_SUCCESS)) { + if ((kmem_alloc(kernel_map, &kaddr, (vm_size_t)*mapsize, VM_KERN_MEMORY_DIAG) == KERN_SUCCESS)) { bzero((void *)kaddr, *mapsize); mapptr = (kd_threadmap *)kaddr; - } else - return (0); + } else { + return 0; + } tts_mapsize = tts_count * sizeof(struct tts); - if ((kmem_alloc(kernel_map, &kaddr, (vm_size_t)tts_mapsize) == KERN_SUCCESS)) { + if ((kmem_alloc(kernel_map, &kaddr, (vm_size_t)tts_mapsize, VM_KERN_MEMORY_DIAG) == KERN_SUCCESS)) { bzero((void *)kaddr, tts_mapsize); tts_mapptr = (struct tts *)kaddr; } else { kmem_free(kernel_map, (vm_offset_t)mapptr, *mapsize); - return (0); + return 0; } - /* - * We need to save the procs command string - * and take a reference for each task associated - * with a valid process - */ - - proc_list_lock(); /* - * should use proc_iterate + * Save the proc's name and take a reference for each task associated + * with a valid process. */ - for (p = allproc.lh_first, i=0; p && i < tts_count; p = p->p_list.le_next) { - if (p->p_lflag & P_LEXIT) - continue; + proc_list_lock(); + int i = 0; + ALLPROC_FOREACH(p) { + if (i >= tts_count) { + break; + } + if (p->p_lflag & P_LEXIT) { + continue; + } if (p->task) { task_reference(p->task); tts_mapptr[i].task = p->task; - tts_mapptr[i].pid = p->p_pid; - (void)strlcpy(tts_mapptr[i].task_comm, p->p_comm, sizeof(tts_mapptr[i].task_comm)); + tts_mapptr[i].pid = p->p_pid; + (void)strlcpy(tts_mapptr[i].task_comm, proc_best_name(p), sizeof(tts_mapptr[i].task_comm)); i++; } } @@ -1612,28 +2102,29 @@ kd_threadmap* kdbg_thrmap_init_internal(unsigned int count, unsigned int *mapsiz akrt.map = mapptr; akrt.count = 0; akrt.maxcount = *mapcount; - + for (i = 0; i < tts_count; i++) { akrt.atts = &tts_mapptr[i]; task_act_iterate_wth_args(tts_mapptr[i].task, kdbg_resolve_map, &akrt); - task_deallocate((task_t) tts_mapptr[i].task); + task_deallocate((task_t)tts_mapptr[i].task); } kmem_free(kernel_map, (vm_offset_t)tts_mapptr, tts_mapsize); *mapcount = akrt.count; - return (mapptr); + return mapptr; } static void kdbg_clear(void) { - /* + /* * Clean up the trace buffer * First make sure we're not in * the middle of cutting a trace */ - kdbg_set_tracing_enabled(FALSE, KDEBUG_ENABLE_TRACE); + kernel_debug_disable(); + kdbg_disable_typefilter(); /* * make sure the SLOW_NOLOG is seen @@ -1642,29 +2133,46 @@ kdbg_clear(void) */ IOSleep(100); - global_state_pid = -1; + /* reset kdebug state for each process */ + if (kd_ctrl_page.kdebug_flags & (KDBG_PIDCHECK | KDBG_PIDEXCLUDE)) { + proc_list_lock(); + proc_t p; + ALLPROC_FOREACH(p) { + p->p_kdebug = 0; + } + proc_list_unlock(); + } + kd_ctrl_page.kdebug_flags &= (unsigned int)~KDBG_CKTYPES; kd_ctrl_page.kdebug_flags &= ~(KDBG_NOWRAP | KDBG_RANGECHECK | KDBG_VALCHECK); kd_ctrl_page.kdebug_flags &= ~(KDBG_PIDCHECK | KDBG_PIDEXCLUDE); - - kdbg_disable_typefilter(); + + kd_ctrl_page.oldest_time = 0; delete_buffers(); nkdbufs = 0; /* Clean up the thread map buffer */ - kd_ctrl_page.kdebug_flags &= ~KDBG_MAPINIT; - if (kd_mapptr) { - kmem_free(kernel_map, (vm_offset_t)kd_mapptr, kd_mapsize); - kd_mapptr = (kd_threadmap *) 0; - } - kd_mapsize = 0; - kd_mapcount = 0; + kdbg_clear_thread_map(); RAW_file_offset = 0; RAW_file_written = 0; } +void +kdebug_reset(void) +{ + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + + kdbg_lock_init(); + + kdbg_clear(); + if (kdbg_typefilter) { + typefilter_reject_all(kdbg_typefilter); + typefilter_allow_class(kdbg_typefilter, DBG_TRACE); + } +} + int kdbg_setpid(kd_regtype *kdr) { @@ -1675,7 +2183,7 @@ kdbg_setpid(kd_regtype *kdr) pid = (pid_t)kdr->value1; flag = (int)kdr->value2; - if (pid > 0) { + if (pid >= 0) { if ((p = proc_find(pid)) == NULL) ret = ESRCH; else { @@ -1717,7 +2225,7 @@ kdbg_setpidex(kd_regtype *kdr) pid = (pid_t)kdr->value1; flag = (int)kdr->value2; - if (pid > 0) { + if (pid >= 0) { if ((p = proc_find(pid)) == NULL) ret = ESRCH; else { @@ -1748,68 +2256,132 @@ kdbg_setpidex(kd_regtype *kdr) return(ret); } +/* + * The following functions all operate on the "global" typefilter singleton. + */ /* - * This is for setting a maximum decrementer value + * The tf param is optional, you may pass either a valid typefilter or NULL. + * If you pass a valid typefilter, you release ownership of that typefilter. */ -int -kdbg_setrtcdec(kd_regtype *kdr) +static int +kdbg_initialize_typefilter(typefilter_t tf) { - int ret = 0; - natural_t decval; + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + assert(!kdbg_typefilter); + assert(!kdbg_typefilter_memory_entry); + typefilter_t deallocate_tf = NULL; + + if (!tf && ((tf = deallocate_tf = typefilter_create()) == NULL)) { + return ENOMEM; + } - decval = (natural_t)kdr->value1; + if ((kdbg_typefilter_memory_entry = typefilter_create_memory_entry(tf)) == MACH_PORT_NULL) { + if (deallocate_tf) { + typefilter_deallocate(deallocate_tf); + } + return ENOMEM; + } - if (decval && decval < KDBG_MINRTCDEC) - ret = EINVAL; - else - ret = ENOTSUP; + /* + * The atomic store closes a race window with + * the kdebug_typefilter syscall, which assumes + * that any non-null kdbg_typefilter means a + * valid memory_entry is available. + */ + __c11_atomic_store(((_Atomic typefilter_t*)&kdbg_typefilter), tf, memory_order_release); - return(ret); + return KERN_SUCCESS; } -int -kdbg_enable_typefilter(void) +static int +kdbg_copyin_typefilter(user_addr_t addr, size_t size) { - if (kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) { - /* free the old filter */ - kdbg_disable_typefilter(); + int ret = ENOMEM; + typefilter_t tf; + + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + + if (size != KDBG_TYPEFILTER_BITMAP_SIZE) { + return EINVAL; } - - if (kmem_alloc(kernel_map, (vm_offset_t *)&type_filter_bitmap, KDBG_TYPEFILTER_BITMAP_SIZE) != KERN_SUCCESS) { - return ENOSPC; + + if ((tf = typefilter_create())) { + if ((ret = copyin(addr, tf, KDBG_TYPEFILTER_BITMAP_SIZE)) == 0) { + /* The kernel typefilter must always allow DBG_TRACE */ + typefilter_allow_class(tf, DBG_TRACE); + + /* + * If this is the first typefilter; claim it. + * Otherwise copy and deallocate. + * + * Allocating a typefilter for the copyin allows + * the kernel to hold the invariant that DBG_TRACE + * must always be allowed. + */ + if (!kdbg_typefilter) { + if ((ret = kdbg_initialize_typefilter(tf))) { + return ret; + } + tf = NULL; + } else { + typefilter_copy(kdbg_typefilter, tf); + } + + kdbg_enable_typefilter(); + kdbg_iop_list_callback(kd_ctrl_page.kdebug_iops, KD_CALLBACK_TYPEFILTER_CHANGED, kdbg_typefilter); + } + + if (tf) + typefilter_deallocate(tf); } - - bzero(type_filter_bitmap, KDBG_TYPEFILTER_BITMAP_SIZE); - /* Turn off range and value checks */ + return ret; +} + +/* + * Enable the flags in the control page for the typefilter. Assumes that + * kdbg_typefilter has already been allocated, so events being written + * don't see a bad typefilter. + */ +static void +kdbg_enable_typefilter(void) +{ + assert(kdbg_typefilter); kd_ctrl_page.kdebug_flags &= ~(KDBG_RANGECHECK | KDBG_VALCHECK); - - /* Enable filter checking */ kd_ctrl_page.kdebug_flags |= KDBG_TYPEFILTER_CHECK; kdbg_set_flags(SLOW_CHECKS, 0, TRUE); - return 0; + commpage_update_kdebug_state(); } -int +/* + * Disable the flags in the control page for the typefilter. The typefilter + * may be safely deallocated shortly after this function returns. + */ +static void kdbg_disable_typefilter(void) { - /* Disable filter checking */ kd_ctrl_page.kdebug_flags &= ~KDBG_TYPEFILTER_CHECK; - - /* Turn off slow checks unless pid checks are using them */ - if ( (kd_ctrl_page.kdebug_flags & (KDBG_PIDCHECK | KDBG_PIDEXCLUDE)) ) + + if ((kd_ctrl_page.kdebug_flags & (KDBG_PIDCHECK | KDBG_PIDEXCLUDE))) { kdbg_set_flags(SLOW_CHECKS, 0, TRUE); - else + } else { kdbg_set_flags(SLOW_CHECKS, 0, FALSE); - - if(type_filter_bitmap == NULL) - return 0; + } + commpage_update_kdebug_state(); +} + +uint32_t +kdebug_commpage_state(void) +{ + if (kdebug_enable) { + if (kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) { + return KDEBUG_COMMPAGE_ENABLE_TYPEFILTER | KDEBUG_COMMPAGE_ENABLE_TRACE; + } - vm_offset_t old_bitmap = (vm_offset_t)type_filter_bitmap; - type_filter_bitmap = NULL; + return KDEBUG_COMMPAGE_ENABLE_TRACE; + } - kmem_free(kernel_map, old_bitmap, KDBG_TYPEFILTER_BITMAP_SIZE); return 0; } @@ -1879,48 +2451,295 @@ kdbg_setreg(kd_regtype * kdr) return(ret); } +static int +kdbg_write_to_vnode(caddr_t buffer, size_t size, vnode_t vp, vfs_context_t ctx, off_t file_offset) +{ + return vn_rdwr(UIO_WRITE, vp, buffer, size, file_offset, UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, + vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); +} + int -kdbg_getreg(__unused kd_regtype * kdr) +kdbg_write_v3_chunk_header(user_addr_t buffer, uint32_t tag, uint32_t sub_tag, uint64_t length, vnode_t vp, vfs_context_t ctx) { -#if 0 - int i,j, ret=0; - unsigned int val_1, val_2, val; + int ret = KERN_SUCCESS; + kd_chunk_header_v3 header = { + .tag = tag, + .sub_tag = sub_tag, + .length = length, + }; - switch (kdr->type) { - case KDBG_CLASSTYPE : - val_1 = (kdr->value1 & 0xff); - val_2 = val_1 + 1; - kdlog_beg = (val_1<<24); - kdlog_end = (val_2<<24); - kd_ctrl_page.kdebug_flags &= (unsigned int)~KDBG_CKTYPES; - kd_ctrl_page.kdebug_flags |= (KDBG_RANGECHECK | KDBG_CLASSTYPE); - break; - case KDBG_SUBCLSTYPE : - val_1 = (kdr->value1 & 0xff); - val_2 = (kdr->value2 & 0xff); - val = val_2 + 1; - kdlog_beg = ((val_1<<24) | (val_2 << 16)); - kdlog_end = ((val_1<<24) | (val << 16)); - kd_ctrl_page.kdebug_flags &= (unsigned int)~KDBG_CKTYPES; - kd_ctrl_page.kdebug_flags |= (KDBG_RANGECHECK | KDBG_SUBCLSTYPE); - break; - case KDBG_RANGETYPE : - kdlog_beg = (kdr->value1); - kdlog_end = (kdr->value2); - kd_ctrl_page.kdebug_flags &= (unsigned int)~KDBG_CKTYPES; - kd_ctrl_page.kdebug_flags |= (KDBG_RANGECHECK | KDBG_RANGETYPE); - break; - case KDBG_TYPENONE : - kd_ctrl_page.kdebug_flags &= (unsigned int)~KDBG_CKTYPES; - kdlog_beg = 0; - kdlog_end = 0; - break; - default : - ret = EINVAL; - break; + // Check that only one of them is valid + assert(!buffer ^ !vp); + assert((vp == NULL) || (ctx != NULL)); + + // Write the 8-byte future_chunk_timestamp field in the payload + if (buffer || vp) { + if (vp) { + ret = kdbg_write_to_vnode((caddr_t)&header, sizeof(kd_chunk_header_v3), vp, ctx, RAW_file_offset); + if (ret) { + goto write_error; + } + RAW_file_offset += (sizeof(kd_chunk_header_v3)); + } + else { + ret = copyout(&header, buffer, sizeof(kd_chunk_header_v3)); + if (ret) { + goto write_error; + } + } + } +write_error: + return ret; +} + +int +kdbg_write_v3_chunk_header_to_buffer(void * buffer, uint32_t tag, uint32_t sub_tag, uint64_t length) +{ + kd_chunk_header_v3 header = { + .tag = tag, + .sub_tag = sub_tag, + .length = length, + }; + + if (!buffer) { + return 0; + } + + memcpy(buffer, &header, sizeof(kd_chunk_header_v3)); + + return (sizeof(kd_chunk_header_v3)); +} + +int +kdbg_write_v3_chunk_to_fd(uint32_t tag, uint32_t sub_tag, uint64_t length, void *payload, uint64_t payload_size, int fd) +{ + proc_t p; + struct vfs_context context; + struct fileproc *fp; + vnode_t vp; + p = current_proc(); + + proc_fdlock(p); + if ( (fp_lookup(p, fd, &fp, 1)) ) { + proc_fdunlock(p); + return EFAULT; + } + + context.vc_thread = current_thread(); + context.vc_ucred = fp->f_fglob->fg_cred; + + if (FILEGLOB_DTYPE(fp->f_fglob) != DTYPE_VNODE) { + fp_drop(p, fd, fp, 1); + proc_fdunlock(p); + return EBADF; + } + vp = (struct vnode *) fp->f_fglob->fg_data; + proc_fdunlock(p); + + if ( (vnode_getwithref(vp)) == 0 ) { + RAW_file_offset = fp->f_fglob->fg_offset; + + kd_chunk_header_v3 chunk_header = { + .tag = tag, + .sub_tag = sub_tag, + .length = length, + }; + + int ret = kdbg_write_to_vnode((caddr_t) &chunk_header, sizeof(kd_chunk_header_v3), vp, &context, RAW_file_offset); + if (!ret) { + RAW_file_offset += sizeof(kd_chunk_header_v3); + } + + ret = kdbg_write_to_vnode((caddr_t) payload, (size_t) payload_size, vp, &context, RAW_file_offset); + if (!ret) { + RAW_file_offset += payload_size; + } + + fp->f_fglob->fg_offset = RAW_file_offset; + vnode_put(vp); } -#endif /* 0 */ - return(EINVAL); + + fp_drop(p, fd, fp, 0); + return KERN_SUCCESS; +} + +user_addr_t +kdbg_write_v3_event_chunk_header(user_addr_t buffer, uint32_t tag, uint64_t length, vnode_t vp, vfs_context_t ctx) +{ + uint64_t future_chunk_timestamp = 0; + length += sizeof(uint64_t); + + if (kdbg_write_v3_chunk_header(buffer, tag, V3_EVENT_DATA_VERSION, length, vp, ctx)) { + return 0; + } + if (buffer) { + buffer += sizeof(kd_chunk_header_v3); + } + + // Check that only one of them is valid + assert(!buffer ^ !vp); + assert((vp == NULL) || (ctx != NULL)); + + // Write the 8-byte future_chunk_timestamp field in the payload + if (buffer || vp) { + if (vp) { + int ret = kdbg_write_to_vnode((caddr_t)&future_chunk_timestamp, sizeof(uint64_t), vp, ctx, RAW_file_offset); + if (!ret) { + RAW_file_offset += (sizeof(uint64_t)); + } + } + else { + if (copyout(&future_chunk_timestamp, buffer, sizeof(uint64_t))) { + return 0; + } + } + } + + return (buffer + sizeof(uint64_t)); +} + +int +kdbg_write_v3_header(user_addr_t user_header, size_t *user_header_size, int fd) +{ + int ret = KERN_SUCCESS; + + uint8_t* cpumap = 0; + uint32_t cpumap_size = 0; + uint32_t thrmap_size = 0; + + size_t bytes_needed = 0; + + // Check that only one of them is valid + assert(!user_header ^ !fd); + assert(user_header_size); + + if ( !(kd_ctrl_page.kdebug_flags & KDBG_BUFINIT) ) { + ret = EINVAL; + goto bail; + } + + if ( !(user_header || fd) ) { + ret = EINVAL; + goto bail; + } + + // Initialize the cpu map + ret = kdbg_cpumap_init_internal(kd_ctrl_page.kdebug_iops, kd_ctrl_page.kdebug_cpus, &cpumap, &cpumap_size); + if (ret != KERN_SUCCESS) { + goto bail; + } + + // Check if a thread map is initialized + if ( !kd_mapptr ) { + ret = EINVAL; + goto bail; + } + thrmap_size = kd_mapcount * sizeof(kd_threadmap); + + mach_timebase_info_data_t timebase = {0, 0}; + clock_timebase_info(&timebase); + + // Setup the header. + // See v3 header description in sys/kdebug.h for more inforamtion. + kd_header_v3 header = { + .tag = RAW_VERSION3, + .sub_tag = V3_HEADER_VERSION, + .length = (sizeof(kd_header_v3) + cpumap_size - sizeof(kd_cpumap_header)), + .timebase_numer = timebase.numer, + .timebase_denom = timebase.denom, + .timestamp = 0, /* FIXME rdar://problem/22053009 */ + .walltime_secs = 0, + .walltime_usecs = 0, + .timezone_minuteswest = 0, + .timezone_dst = 0, +#if defined(__LP64__) + .flags = 1, +#else + .flags = 0, +#endif + }; + + // If its a buffer, check if we have enough space to copy the header and the maps. + if (user_header) { + bytes_needed = header.length + thrmap_size + (2 * sizeof(kd_chunk_header_v3)); + if (*user_header_size < bytes_needed) { + ret = EINVAL; + goto bail; + } + } + + // Start writing the header + if (fd) { + void *hdr_ptr = (void *)(((uintptr_t) &header) + sizeof(kd_chunk_header_v3)); + size_t payload_size = (sizeof(kd_header_v3) - sizeof(kd_chunk_header_v3)); + + ret = kdbg_write_v3_chunk_to_fd(RAW_VERSION3, V3_HEADER_VERSION, header.length, hdr_ptr, payload_size, fd); + if (ret) { + goto bail; + } + } + else { + if (copyout(&header, user_header, sizeof(kd_header_v3))) { + ret = EFAULT; + goto bail; + } + // Update the user pointer + user_header += sizeof(kd_header_v3); + } + + // Write a cpu map. This is a sub chunk of the header + cpumap = (uint8_t*)((uintptr_t) cpumap + sizeof(kd_cpumap_header)); + size_t payload_size = (size_t)(cpumap_size - sizeof(kd_cpumap_header)); + if (fd) { + ret = kdbg_write_v3_chunk_to_fd(V3_CPU_MAP, V3_CPUMAP_VERSION, payload_size, (void *)cpumap, payload_size, fd); + if (ret) { + goto bail; + } + } + else { + ret = kdbg_write_v3_chunk_header(user_header, V3_CPU_MAP, V3_CPUMAP_VERSION, payload_size, NULL, NULL); + if (ret) { + goto bail; + } + user_header += sizeof(kd_chunk_header_v3); + if (copyout(cpumap, user_header, payload_size)) { + ret = EFAULT; + goto bail; + } + // Update the user pointer + user_header += payload_size; + } + + // Write a thread map + if (fd) { + ret = kdbg_write_v3_chunk_to_fd(V3_THREAD_MAP, V3_THRMAP_VERSION, thrmap_size, (void *)kd_mapptr, thrmap_size, fd); + if (ret) { + goto bail; + } + } + else { + ret = kdbg_write_v3_chunk_header(user_header, V3_THREAD_MAP, V3_THRMAP_VERSION, thrmap_size, NULL, NULL); + if (ret) { + goto bail; + } + user_header += sizeof(kd_chunk_header_v3); + if (copyout(kd_mapptr, user_header, thrmap_size)) { + ret = EFAULT; + goto bail; + } + user_header += thrmap_size; + } + + if (fd) { + RAW_file_written += bytes_needed; + } + + *user_header_size = bytes_needed; +bail: + if (cpumap) { + kmem_free(kernel_map, (vm_offset_t)cpumap, cpumap_size); + } + return (ret); } int @@ -1973,217 +2792,375 @@ kdbg_readcurthrmap(user_addr_t buffer, size_t *bufsize) return (ret); } -int -kdbg_readthrmap(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) +static int +kdbg_write_v1_header(boolean_t write_thread_map, vnode_t vp, vfs_context_t ctx) { - int avail = *number; int ret = 0; - uint32_t count = 0; - unsigned int mapsize; - - count = avail/sizeof (kd_threadmap); + RAW_header header; + clock_sec_t secs; + clock_usec_t usecs; + char *pad_buf; + uint32_t pad_size; + uint32_t extra_thread_count = 0; + uint32_t cpumap_size; + size_t map_size = 0; + size_t map_count = 0; + + if (write_thread_map) { + assert(kd_ctrl_page.kdebug_flags & KDBG_MAPINIT); + map_count = kd_mapcount; + map_size = map_count * sizeof(kd_threadmap); + } - mapsize = kd_mapcount * sizeof(kd_threadmap); + /* + * Without the buffers initialized, we cannot construct a CPU map or a + * thread map, and cannot write a header. + */ + if (!(kd_ctrl_page.kdebug_flags & KDBG_BUFINIT)) { + return EINVAL; + } - if (count && (count <= kd_mapcount)) - { - if ((kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) && kd_mapsize && kd_mapptr) - { - if (*number < mapsize) - ret = EINVAL; - else - { - if (vp) - { - RAW_header header; - clock_sec_t secs; - clock_usec_t usecs; - char *pad_buf; - uint32_t pad_size; - uint32_t extra_thread_count = 0; - uint32_t cpumap_size; - - /* - * To write a RAW_VERSION1+ file, we - * must embed a cpumap in the "padding" - * used to page align the events folloing - * the threadmap. If the threadmap happens - * to not require enough padding, we - * artificially increase its footprint - * until it needs enough padding. - */ + /* + * To write a RAW_VERSION1+ file, we must embed a cpumap in the + * "padding" used to page align the events following the threadmap. If + * the threadmap happens to not require enough padding, we artificially + * increase its footprint until it needs enough padding. + */ - pad_size = PAGE_SIZE - ((sizeof(RAW_header) + (count * sizeof(kd_threadmap))) & PAGE_MASK_64); - cpumap_size = sizeof(kd_cpumap_header) + kd_ctrl_page.kdebug_cpus * sizeof(kd_cpumap); + assert(vp); + assert(ctx); - if (cpumap_size > pad_size) { - /* Force an overflow onto the next page, we get a full page of padding */ - extra_thread_count = (pad_size / sizeof(kd_threadmap)) + 1; - } + pad_size = PAGE_16KB - ((sizeof(RAW_header) + map_size) & PAGE_MASK_64); + cpumap_size = sizeof(kd_cpumap_header) + kd_ctrl_page.kdebug_cpus * sizeof(kd_cpumap); - header.version_no = RAW_VERSION1; - header.thread_count = count + extra_thread_count; + if (cpumap_size > pad_size) { + /* If the cpu map doesn't fit in the current available pad_size, + * we increase the pad_size by 16K. We do this so that the event + * data is always available on a page aligned boundary for both + * 4k and 16k systems. We enforce this alignment for the event + * data so that we can take advantage of optimized file/disk writes. + */ + pad_size += PAGE_16KB; + } - clock_get_calendar_microtime(&secs, &usecs); - header.TOD_secs = secs; - header.TOD_usecs = usecs; + /* The way we are silently embedding a cpumap in the "padding" is by artificially + * increasing the number of thread entries. However, we'll also need to ensure that + * the cpumap is embedded in the last 4K page before when the event data is expected. + * This way the tools can read the data starting the next page boundary on both + * 4K and 16K systems preserving compatibility with older versions of the tools + */ + if (pad_size > PAGE_4KB) { + pad_size -= PAGE_4KB; + extra_thread_count = (pad_size / sizeof(kd_threadmap)) + 1; + } - ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)&header, sizeof(RAW_header), RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - if (ret) - goto write_error; - RAW_file_offset += sizeof(RAW_header); + memset(&header, 0, sizeof(header)); + header.version_no = RAW_VERSION1; + header.thread_count = map_count + extra_thread_count; - ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)kd_mapptr, mapsize, RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - if (ret) - goto write_error; - RAW_file_offset += mapsize; + clock_get_calendar_microtime(&secs, &usecs); + header.TOD_secs = secs; + header.TOD_usecs = usecs; - if (extra_thread_count) { - pad_size = extra_thread_count * sizeof(kd_threadmap); - pad_buf = (char *)kalloc(pad_size); - memset(pad_buf, 0, pad_size); + ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)&header, sizeof(RAW_header), RAW_file_offset, + UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); + if (ret) { + goto write_error; + } + RAW_file_offset += sizeof(RAW_header); + RAW_file_written += sizeof(RAW_header); + + if (write_thread_map) { + ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)kd_mapptr, map_size, RAW_file_offset, + UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); + if (ret) { + goto write_error; + } - ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)pad_buf, pad_size, RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - kfree(pad_buf, pad_size); + RAW_file_offset += map_size; + RAW_file_written += map_size; + } - if (ret) - goto write_error; - RAW_file_offset += pad_size; + if (extra_thread_count) { + pad_size = extra_thread_count * sizeof(kd_threadmap); + pad_buf = kalloc(pad_size); + if (!pad_buf) { + ret = ENOMEM; + goto write_error; + } + memset(pad_buf, 0, pad_size); - } - - pad_size = PAGE_SIZE - (RAW_file_offset & PAGE_MASK_64); - if (pad_size) { - pad_buf = (char *)kalloc(pad_size); - memset(pad_buf, 0, pad_size); - - /* - * embed a cpumap in the padding bytes. - * older code will skip this. - * newer code will know how to read it. - */ - uint32_t temp = pad_size; - if (kdbg_cpumap_init_internal(kd_ctrl_page.kdebug_iops, kd_ctrl_page.kdebug_cpus, (uint8_t**)&pad_buf, &temp) != KERN_SUCCESS) { - memset(pad_buf, 0, pad_size); - } + ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)pad_buf, pad_size, RAW_file_offset, + UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); + kfree(pad_buf, pad_size); + if (ret) { + goto write_error; + } - ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)pad_buf, pad_size, RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - kfree(pad_buf, pad_size); + RAW_file_offset += pad_size; + RAW_file_written += pad_size; + } - if (ret) - goto write_error; - RAW_file_offset += pad_size; - } - RAW_file_written += sizeof(RAW_header) + mapsize + pad_size; + pad_size = PAGE_SIZE - (RAW_file_offset & PAGE_MASK_64); + if (pad_size) { + pad_buf = (char *)kalloc(pad_size); + if (!pad_buf) { + ret = ENOMEM; + goto write_error; + } + memset(pad_buf, 0, pad_size); - } else { - if (copyout(kd_mapptr, buffer, mapsize)) - ret = EINVAL; - } - } + /* + * embed a cpumap in the padding bytes. + * older code will skip this. + * newer code will know how to read it. + */ + uint32_t temp = pad_size; + if (kdbg_cpumap_init_internal(kd_ctrl_page.kdebug_iops, kd_ctrl_page.kdebug_cpus, (uint8_t**)&pad_buf, &temp) != KERN_SUCCESS) { + memset(pad_buf, 0, pad_size); } - else - ret = EINVAL; - } - else - ret = EINVAL; - if (ret && vp) - { - count = 0; + ret = vn_rdwr(UIO_WRITE, vp, (caddr_t)pad_buf, pad_size, RAW_file_offset, + UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); + kfree(pad_buf, pad_size); + if (ret) { + goto write_error; + } - vn_rdwr(UIO_WRITE, vp, (caddr_t)&count, sizeof(uint32_t), RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - RAW_file_offset += sizeof(uint32_t); - RAW_file_written += sizeof(uint32_t); + RAW_file_offset += pad_size; + RAW_file_written += pad_size; } + write_error: - if ((kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) && kd_mapsize && kd_mapptr) - { + return ret; +} + +static void +kdbg_clear_thread_map(void) +{ + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + + if (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT) { + assert(kd_mapptr != NULL); kmem_free(kernel_map, (vm_offset_t)kd_mapptr, kd_mapsize); - kd_ctrl_page.kdebug_flags &= ~KDBG_MAPINIT; + kd_mapptr = NULL; kd_mapsize = 0; - kd_mapptr = (kd_threadmap *) 0; kd_mapcount = 0; - } - return(ret); + kd_ctrl_page.kdebug_flags &= ~KDBG_MAPINIT; + } } - +/* + * Write out a version 1 header and the thread map, if it is initialized, to a + * vnode. Used by KDWRITEMAP and kdbg_dump_trace_to_file. + * + * Returns write errors from vn_rdwr if a write fails. Returns ENODATA if the + * thread map has not been initialized, but the header will still be written. + * Returns ENOMEM if padding could not be allocated. Returns 0 otherwise. + */ static int -kdbg_set_nkdbufs(unsigned int value) +kdbg_write_thread_map(vnode_t vp, vfs_context_t ctx) { - /* - * We allow a maximum buffer size of 50% of either ram or max mapped address, whichever is smaller - * 'value' is the desired number of trace entries - */ - unsigned int max_entries = (sane_size/2) / sizeof(kd_buf); + int ret = 0; + boolean_t map_initialized; - if (value <= max_entries) - return (value); - else - return (max_entries); -} + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + assert(ctx != NULL); + map_initialized = (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT); + ret = kdbg_write_v1_header(map_initialized, vp, ctx); + if (ret == 0) { + if (map_initialized) { + kdbg_clear_thread_map(); + } else { + ret = ENODATA; + } + } + + return ret; +} + +/* + * Copy out the thread map to a user space buffer. Used by KDTHRMAP. + * + * Returns copyout errors if the copyout fails. Returns ENODATA if the thread + * map has not been initialized. Returns EINVAL if the buffer provided is not + * large enough for the entire thread map. Returns 0 otherwise. + */ static int -kdbg_enable_bg_trace(void) +kdbg_copyout_thread_map(user_addr_t buffer, size_t *buffer_size) { + boolean_t map_initialized; + size_t map_size; int ret = 0; - if (kdlog_bg_trace == TRUE && kdlog_bg_trace_running == FALSE && n_storage_buffers == 0) { - nkdbufs = bg_nkdbufs; - ret = kdbg_reinit(FALSE); - if (0 == ret) { - kdbg_set_tracing_enabled(TRUE, KDEBUG_ENABLE_TRACE); - kdlog_bg_trace_running = TRUE; - } + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + assert(buffer_size != NULL); + + map_initialized = (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT); + if (!map_initialized) { + return ENODATA; + } + + map_size = kd_mapcount * sizeof(kd_threadmap); + if (*buffer_size < map_size) { + return EINVAL; } + + ret = copyout(kd_mapptr, buffer, map_size); + if (ret == 0) { + kdbg_clear_thread_map(); + } + return ret; } -static void -kdbg_disable_bg_trace(void) +int +kdbg_readthrmap_v3(user_addr_t buffer, size_t buffer_size, int fd) { - if (kdlog_bg_trace_running == TRUE) { - kdlog_bg_trace_running = FALSE; - kdbg_clear(); + int ret = 0; + boolean_t map_initialized; + size_t map_size; + + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); + + if ((!fd && !buffer) || (fd && buffer)) { + return EINVAL; + } + + map_initialized = (kd_ctrl_page.kdebug_flags & KDBG_MAPINIT); + map_size = kd_mapcount * sizeof(kd_threadmap); + + if (map_initialized && (buffer_size >= map_size)) + { + ret = kdbg_write_v3_header(buffer, &buffer_size, fd); + + if (ret == 0) { + kdbg_clear_thread_map(); + } + } else { + ret = EINVAL; } + + return ret; } +static void +kdbg_set_nkdbufs(unsigned int value) +{ + /* + * We allow a maximum buffer size of 50% of either ram or max mapped + * address, whichever is smaller 'value' is the desired number of trace + * entries + */ + unsigned int max_entries = (sane_size / 2) / sizeof(kd_buf); + if (value <= max_entries) { + nkdbufs = value; + } else { + nkdbufs = max_entries; + } +} /* - * This function is provided for the CHUD toolkit only. - * int val: - * zero disables kdebug_chudhook function call - * non-zero enables kdebug_chudhook function call - * char *fn: - * address of the enabled kdebug_chudhook function -*/ + * Block until there are `n_storage_threshold` storage units filled with + * events or `timeout_ms` milliseconds have passed. If `locked_wait` is true, + * `ktrace_lock` is held while waiting. This is necessary while waiting to + * write events out of the buffers. + * + * Returns true if the threshold was reached and false otherwise. + * + * Called with `ktrace_lock` locked and interrupts enabled. + */ +static boolean_t +kdbg_wait(uint64_t timeout_ms, boolean_t locked_wait) +{ + int wait_result = THREAD_AWAKENED; + uint64_t abstime = 0; -void -kdbg_control_chud(int val, void *fn) + if (timeout_ms != 0) { + uint64_t ns = timeout_ms * NSEC_PER_MSEC; + nanoseconds_to_absolutetime(ns, &abstime); + clock_absolutetime_interval_to_deadline(abstime, &abstime); + } + + boolean_t s = ml_set_interrupts_enabled(FALSE); + if (!s) { + panic("kdbg_wait() called with interrupts disabled"); + } + lck_spin_lock(kdw_spin_lock); + + if (!locked_wait) { + /* drop the mutex to allow others to access trace */ + lck_mtx_unlock(ktrace_lock); + } + + while (wait_result == THREAD_AWAKENED && + kd_ctrl_page.kds_inuse_count < n_storage_threshold) + { + kds_waiter = 1; + + if (abstime) { + wait_result = lck_spin_sleep_deadline(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE, abstime); + } else { + wait_result = lck_spin_sleep(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE); + } + + kds_waiter = 0; + } + + /* check the count under the spinlock */ + boolean_t threshold_exceeded = (kd_ctrl_page.kds_inuse_count >= n_storage_threshold); + + lck_spin_unlock(kdw_spin_lock); + ml_set_interrupts_enabled(s); + + if (!locked_wait) { + /* pick the mutex back up again */ + lck_mtx_lock(ktrace_lock); + } + + /* write out whether we've exceeded the threshold */ + return threshold_exceeded; +} + +/* + * Wakeup a thread waiting using `kdbg_wait` if there are at least + * `n_storage_threshold` storage units in use. + */ +static void +kdbg_wakeup(void) { - kdbg_lock_init(); - - if (val) { - /* enable chudhook */ - kdebug_chudhook = fn; - kdbg_set_flags(SLOW_CHUD, KDEBUG_ENABLE_CHUD, TRUE); + boolean_t need_kds_wakeup = FALSE; + + /* + * Try to take the lock here to synchronize with the waiter entering + * the blocked state. Use the try mode to prevent deadlocks caused by + * re-entering this routine due to various trace points triggered in the + * lck_spin_sleep_xxxx routines used to actually enter one of our 2 wait + * conditions. No problem if we fail, there will be lots of additional + * events coming in that will eventually succeed in grabbing this lock. + */ + boolean_t s = ml_set_interrupts_enabled(FALSE); + + if (lck_spin_try_lock(kdw_spin_lock)) { + if (kds_waiter && + (kd_ctrl_page.kds_inuse_count >= n_storage_threshold)) + { + kds_waiter = 0; + need_kds_wakeup = TRUE; + } + lck_spin_unlock(kdw_spin_lock); } - else { - /* disable chudhook */ - kdbg_set_flags(SLOW_CHUD, KDEBUG_ENABLE_CHUD, FALSE); - kdebug_chudhook = 0; + + ml_set_interrupts_enabled(s); + + if (need_kds_wakeup == TRUE) { + wakeup(&kds_waiter); } } - int kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) { @@ -2192,58 +3169,78 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) unsigned int value = 0; kd_regtype kd_Reg; kbufinfo_t kd_bufinfo; - pid_t curpid; - proc_t p, curproc; + proc_t p; if (name[0] == KERN_KDGETENTROPY || name[0] == KERN_KDWRITETR || + name[0] == KERN_KDWRITETR_V3 || name[0] == KERN_KDWRITEMAP || + name[0] == KERN_KDWRITEMAP_V3 || name[0] == KERN_KDEFLAGS || name[0] == KERN_KDDFLAGS || name[0] == KERN_KDENABLE || - name[0] == KERN_KDENABLE_BG_TRACE || - name[0] == KERN_KDSETBUF) { - - if ( namelen < 2 ) - return(EINVAL); + name[0] == KERN_KDSETBUF) + { + if (namelen < 2) { + return EINVAL; + } value = name[1]; } - + kdbg_lock_init(); + assert(kd_ctrl_page.kdebug_flags & KDBG_LOCKINIT); - if ( !(kd_ctrl_page.kdebug_flags & KDBG_LOCKINIT)) - return(ENOSPC); + lck_mtx_lock(ktrace_lock); - lck_mtx_lock(kd_trace_mtx_sysctl); + /* + * Some requests only require "read" access to kdebug trace. Regardless, + * tell ktrace that a configuration or read is occurring (and see if it's + * allowed). + */ + if (name[0] != KERN_KDGETBUF && + name[0] != KERN_KDGETREG && + name[0] != KERN_KDREADCURTHRMAP && + name[0] != KERN_KDGETENTROPY) + { + if ((ret = ktrace_configure(KTRACE_KDEBUG))) { + goto out; + } + } else { + if ((ret = ktrace_read_check())) { + goto out; + } + } switch(name[0]) { case KERN_KDGETBUF: - /* - * Does not alter the global_state_pid - * This is a passive request. - */ if (size < sizeof(kd_bufinfo.nkdbufs)) { /* * There is not enough room to return even * the first element of the info structure. */ ret = EINVAL; - goto out; + break; } + + memset(&kd_bufinfo, 0, sizeof(kd_bufinfo)); + kd_bufinfo.nkdbufs = nkdbufs; kd_bufinfo.nkdthreads = kd_mapcount; - + if ( (kd_ctrl_page.kdebug_slowcheck & SLOW_NOLOG) ) kd_bufinfo.nolog = 1; else kd_bufinfo.nolog = 0; - + kd_bufinfo.flags = kd_ctrl_page.kdebug_flags; #if defined(__LP64__) kd_bufinfo.flags |= KDBG_LP64; #endif - kd_bufinfo.bufid = global_state_pid; - + { + int pid = ktrace_get_owning_pid(); + kd_bufinfo.bufid = (pid == 0 ? -1 : pid); + } + if (size >= sizeof(kd_bufinfo)) { /* * Provide all the info we have @@ -2258,67 +3255,31 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) if (copyout(&kd_bufinfo, where, size)) ret = EINVAL; } - goto out; - + break; + case KERN_KDGETENTROPY: { /* Obsolescent - just fake with a random buffer */ char *buffer = (char *) kalloc(size); read_frandom((void *) buffer, size); ret = copyout(buffer, where, size); kfree(buffer, size); - goto out; + break; } - - case KERN_KDENABLE_BG_TRACE: - bg_nkdbufs = kdbg_set_nkdbufs(value); - kdlog_bg_trace = TRUE; - ret = kdbg_enable_bg_trace(); - goto out; - - case KERN_KDDISABLE_BG_TRACE: - kdlog_bg_trace = FALSE; - kdbg_disable_bg_trace(); - goto out; - } - - if ((curproc = current_proc()) != NULL) - curpid = curproc->p_pid; - else { - ret = ESRCH; - goto out; - } - if (global_state_pid == -1) - global_state_pid = curpid; - else if (global_state_pid != curpid) { - if ((p = proc_find(global_state_pid)) == NULL) { - /* - * The global pid no longer exists - */ - global_state_pid = curpid; - } else { - /* - * The global pid exists, deny this request - */ - proc_rele(p); - ret = EBUSY; - goto out; - } - } + case KERN_KDREADCURTHRMAP: + ret = kdbg_readcurthrmap(where, sizep); + break; - switch(name[0]) { case KERN_KDEFLAGS: - kdbg_disable_bg_trace(); - value &= KDBG_USERFLAGS; kd_ctrl_page.kdebug_flags |= value; break; - case KERN_KDDFLAGS: - kdbg_disable_bg_trace(); + case KERN_KDDFLAGS: value &= KDBG_USERFLAGS; kd_ctrl_page.kdebug_flags &= ~value; break; + case KERN_KDENABLE: /* * Enable tracing mechanism. Two types: @@ -2341,23 +3302,26 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) } else { - kdbg_set_tracing_enabled(FALSE, 0); + if (!kdebug_enable) { + break; + } + + kernel_debug_disable(); } break; - case KERN_KDSETBUF: - kdbg_disable_bg_trace(); - nkdbufs = kdbg_set_nkdbufs(value); + case KERN_KDSETBUF: + kdbg_set_nkdbufs(value); break; - case KERN_KDSETUP: - kdbg_disable_bg_trace(); + case KERN_KDSETUP: ret = kdbg_reinit(FALSE); break; + case KERN_KDREMOVE: - kdbg_clear(); - ret = kdbg_enable_bg_trace(); + ktrace_reset(KTRACE_KDEBUG); break; + case KERN_KDSETREG: if(size < sizeof(kd_regtype)) { ret = EINVAL; @@ -2367,27 +3331,22 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) ret = EINVAL; break; } - kdbg_disable_bg_trace(); ret = kdbg_setreg(&kd_Reg); break; - case KERN_KDGETREG: - if (size < sizeof(kd_regtype)) { - ret = EINVAL; - break; - } - ret = kdbg_getreg(&kd_Reg); - if (copyout(&kd_Reg, where, sizeof(kd_regtype))) { - ret = EINVAL; - } - kdbg_disable_bg_trace(); + case KERN_KDGETREG: + ret = EINVAL; break; + case KERN_KDREADTR: - ret = kdbg_read(where, sizep, NULL, NULL); + ret = kdbg_read(where, sizep, NULL, NULL, RAW_VERSION1); break; + case KERN_KDWRITETR: + case KERN_KDWRITETR_V3: case KERN_KDWRITEMAP: + case KERN_KDWRITEMAP_V3: { struct vfs_context context; struct fileproc *fp; @@ -2395,37 +3354,8 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) vnode_t vp; int fd; - kdbg_disable_bg_trace(); - - if (name[0] == KERN_KDWRITETR) { - int s; - int wait_result = THREAD_AWAKENED; - u_int64_t abstime; - u_int64_t ns; - - if (*sizep) { - ns = ((u_int64_t)*sizep) * (u_int64_t)(1000 * 1000); - nanoseconds_to_absolutetime(ns, &abstime ); - clock_absolutetime_interval_to_deadline( abstime, &abstime ); - } else - abstime = 0; - - s = ml_set_interrupts_enabled(FALSE); - lck_spin_lock(kdw_spin_lock); - - while (wait_result == THREAD_AWAKENED && kd_ctrl_page.kds_inuse_count < n_storage_threshold) { - - kds_waiter = 1; - - if (abstime) - wait_result = lck_spin_sleep_deadline(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE, abstime); - else - wait_result = lck_spin_sleep(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE); - - kds_waiter = 0; - } - lck_spin_unlock(kdw_spin_lock); - ml_set_interrupts_enabled(s); + if (name[0] == KERN_KDWRITETR || name[0] == KERN_KDWRITETR_V3) { + (void)kdbg_wait(size, TRUE); } p = current_proc(); fd = value; @@ -2450,80 +3380,36 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) if ((ret = vnode_getwithref(vp)) == 0) { RAW_file_offset = fp->f_fglob->fg_offset; - if (name[0] == KERN_KDWRITETR) { + if (name[0] == KERN_KDWRITETR || name[0] == KERN_KDWRITETR_V3) { number = nkdbufs * sizeof(kd_buf); - KERNEL_DEBUG_CONSTANT((TRACEDBG_CODE(DBG_TRACE_INFO, 3)) | DBG_FUNC_START, 0, 0, 0, 0, 0); - ret = kdbg_read(0, &number, vp, &context); - KERNEL_DEBUG_CONSTANT((TRACEDBG_CODE(DBG_TRACE_INFO, 3)) | DBG_FUNC_END, number, 0, 0, 0, 0); + KERNEL_DEBUG_CONSTANT(TRACE_WRITING_EVENTS | DBG_FUNC_START, 0, 0, 0, 0, 0); + if (name[0] == KERN_KDWRITETR_V3) + ret = kdbg_read(0, &number, vp, &context, RAW_VERSION3); + else + ret = kdbg_read(0, &number, vp, &context, RAW_VERSION1); + KERNEL_DEBUG_CONSTANT(TRACE_WRITING_EVENTS | DBG_FUNC_END, number, 0, 0, 0, 0); *sizep = number; } else { number = kd_mapcount * sizeof(kd_threadmap); - kdbg_readthrmap(0, &number, vp, &context); + if (name[0] == KERN_KDWRITEMAP_V3) { + ret = kdbg_readthrmap_v3(0, number, fd); + } else { + ret = kdbg_write_thread_map(vp, &context); + } } fp->f_fglob->fg_offset = RAW_file_offset; - vnode_put(vp); - } - fp_drop(p, fd, fp, 0); - - break; - } - case KERN_KDBUFWAIT: - { - /* WRITETR lite -- just block until there's data */ - int s; - int wait_result = THREAD_AWAKENED; - u_int64_t abstime; - u_int64_t ns; - size_t number = 0; - - kdbg_disable_bg_trace(); - - - if (*sizep) { - ns = ((u_int64_t)*sizep) * (u_int64_t)(1000 * 1000); - nanoseconds_to_absolutetime(ns, &abstime ); - clock_absolutetime_interval_to_deadline( abstime, &abstime ); - } else - abstime = 0; - - s = ml_set_interrupts_enabled(FALSE); - if( !s ) - panic("trying to wait with interrupts off"); - lck_spin_lock(kdw_spin_lock); - - /* drop the mutex so don't exclude others from - * accessing trace - */ - lck_mtx_unlock(kd_trace_mtx_sysctl); - - while (wait_result == THREAD_AWAKENED && - kd_ctrl_page.kds_inuse_count < n_storage_threshold) { - - kds_waiter = 1; - - if (abstime) - wait_result = lck_spin_sleep_deadline(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE, abstime); - else - wait_result = lck_spin_sleep(kdw_spin_lock, 0, &kds_waiter, THREAD_ABORTSAFE); - - kds_waiter = 0; - } - - /* check the count under the spinlock */ - number = (kd_ctrl_page.kds_inuse_count >= n_storage_threshold); - - lck_spin_unlock(kdw_spin_lock); - ml_set_interrupts_enabled(s); - - /* pick the mutex back up again */ - lck_mtx_lock(kd_trace_mtx_sysctl); + vnode_put(vp); + } + fp_drop(p, fd, fp, 0); - /* write out whether we've exceeded the threshold */ - *sizep = number; break; } + case KERN_KDBUFWAIT: + *sizep = kdbg_wait(size, FALSE); + break; + case KERN_KDPIDTR: if (size < sizeof(kd_regtype)) { ret = EINVAL; @@ -2533,10 +3419,10 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) ret = EINVAL; break; } - kdbg_disable_bg_trace(); ret = kdbg_setpid(&kd_Reg); break; + case KERN_KDPIDEX: if (size < sizeof(kd_regtype)) { ret = EINVAL; @@ -2546,56 +3432,33 @@ kdbg_control(int *name, u_int namelen, user_addr_t where, size_t *sizep) ret = EINVAL; break; } - kdbg_disable_bg_trace(); ret = kdbg_setpidex(&kd_Reg); break; + case KERN_KDCPUMAP: ret = kdbg_readcpumap(where, sizep); break; + case KERN_KDTHRMAP: - ret = kdbg_readthrmap(where, sizep, NULL, NULL); - break; - case KERN_KDREADCURTHRMAP: - ret = kdbg_readcurthrmap(where, sizep); + ret = kdbg_copyout_thread_map(where, sizep); break; - case KERN_KDSETRTCDEC: - if (size < sizeof(kd_regtype)) { - ret = EINVAL; - break; - } - if (copyin(where, &kd_Reg, sizeof(kd_regtype))) { - ret = EINVAL; - break; - } - kdbg_disable_bg_trace(); - ret = kdbg_setrtcdec(&kd_Reg); + case KERN_KDSET_TYPEFILTER: { + ret = kdbg_copyin_typefilter(where, size); break; - case KERN_KDSET_TYPEFILTER: - kdbg_disable_bg_trace(); - - if ((kd_ctrl_page.kdebug_flags & KDBG_TYPEFILTER_CHECK) == 0){ - if ((ret = kdbg_enable_typefilter())) - break; - } - - if (size != KDBG_TYPEFILTER_BITMAP_SIZE) { - ret = EINVAL; - break; - } + } - if (copyin(where, type_filter_bitmap, KDBG_TYPEFILTER_BITMAP_SIZE)) { - ret = EINVAL; - break; - } - kdbg_iop_list_callback(kd_ctrl_page.kdebug_iops, KD_CALLBACK_TYPEFILTER_CHANGED, type_filter_bitmap); + case KERN_KDTEST: + ret = kdbg_test(); break; + default: ret = EINVAL; + break; } out: - lck_mtx_unlock(kd_trace_mtx_sysctl); + lck_mtx_unlock(ktrace_lock); return(ret); } @@ -2608,11 +3471,11 @@ out: * move through the lists w/o use of any locks */ int -kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) +kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx, uint32_t file_version) { unsigned int count; unsigned int cpu, min_cpu; - uint64_t mintime, t, barrier = 0; + uint64_t barrier_min = 0, barrier_max = 0, t, earliest_time; int error = 0; kd_buf *tempbuf; uint32_t rcursor; @@ -2627,63 +3490,99 @@ kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) uint32_t old_kdebug_slowcheck; boolean_t lostevents = FALSE; boolean_t out_of_events = FALSE; + boolean_t wrapped = FALSE; + assert(number); count = *number/sizeof(kd_buf); *number = 0; if (count == 0 || !(kd_ctrl_page.kdebug_flags & KDBG_BUFINIT) || kdcopybuf == 0) return EINVAL; + thread_set_eager_preempt(current_thread()); + memset(&lostevent, 0, sizeof(lostevent)); - lostevent.debugid = TRACEDBG_CODE(DBG_TRACE_INFO, 2); + lostevent.debugid = TRACE_LOST_EVENTS; - /* Capture timestamp. Only sort events that have occured before the timestamp. - * Since the iop is being flushed here, its possible that events occur on the AP - * while running live tracing. If we are disabled, no new events should - * occur on the AP. - */ - - if (kd_ctrl_page.enabled) - { - // timestamp is non-zero value - barrier = mach_absolute_time() & KDBG_TIMESTAMP_MASK; + /* + * Capture the current time. Only sort events that have occured + * before now. Since the IOPs are being flushed here, it is possible + * that events occur on the AP while running live tracing. If we are + * disabled, no new events should occur on the AP. + */ + if (kd_ctrl_page.enabled) { + barrier_max = mach_absolute_time() & KDBG_TIMESTAMP_MASK; } - - // Request each IOP to provide us with up to date entries before merging buffers together. - kdbg_iop_list_callback(kd_ctrl_page.kdebug_iops, KD_CALLBACK_SYNC_FLUSH, NULL); /* - * because we hold kd_trace_mtx_sysctl, no other control threads can - * be playing with kdebug_flags... the code that cuts new events could - * be running, but it grabs kds_spin_lock if it needs to acquire a new - * storage chunk which is where it examines kdebug_flags... it its adding - * to the same chunk we're reading from, no problem... + * Request each IOP to provide us with up to date entries before merging + * buffers together. */ + kdbg_iop_list_callback(kd_ctrl_page.kdebug_iops, KD_CALLBACK_SYNC_FLUSH, NULL); - disable_wrap(&old_kdebug_slowcheck, &old_kdebug_flags); + /* + * Disable wrap so storage units cannot be stolen out from underneath us + * while merging events. + * + * Because we hold ktrace_lock, no other control threads can be playing + * with kdebug_flags. The code that emits new events could be running, + * but it grabs kds_spin_lock if it needs to acquire a new storage + * chunk, which is where it examines kdebug_flags. If it is adding to + * the same chunk we're reading from, check for that below. + */ + wrapped = disable_wrap(&old_kdebug_slowcheck, &old_kdebug_flags); if (count > nkdbufs) count = nkdbufs; - if ((tempbuf_count = count) > KDCOPYBUF_COUNT) - tempbuf_count = KDCOPYBUF_COUNT; + if ((tempbuf_count = count) > KDCOPYBUF_COUNT) { + tempbuf_count = KDCOPYBUF_COUNT; + } + + /* + * If the buffers have wrapped, capture the earliest time where there + * are events for all CPUs and do not emit additional lost events for + * oldest storage units. + */ + if (wrapped) { + barrier_min = kd_ctrl_page.oldest_time; + kd_ctrl_page.kdebug_flags &= ~KDBG_WRAPPED; + kd_ctrl_page.oldest_time = 0; + + for (cpu = 0, kdbp = &kdbip[0]; cpu < kd_ctrl_page.kdebug_cpus; cpu++, kdbp++) { + if ((kdsp = kdbp->kd_list_head).raw == KDS_PTR_NULL) { + continue; + } + kdsp_actual = POINTER_FROM_KDS_PTR(kdsp); + kdsp_actual->kds_lostevents = FALSE; + } + } while (count) { tempbuf = kdcopybuf; tempbuf_number = 0; - // While space + if (wrapped) { + /* Trace a single lost events event for wrapping. */ + kdbg_set_timestamp_and_cpu(&lostevent, barrier_min, 0); + *tempbuf = lostevent; + wrapped = FALSE; + goto nextevent; + } + + /* While space left in merged events scratch buffer. */ while (tempbuf_count) { - mintime = 0xffffffffffffffffULL; + earliest_time = UINT64_MAX; min_kdbp = NULL; min_cpu = 0; - // Check all CPUs + /* Check each CPU's buffers. */ for (cpu = 0, kdbp = &kdbip[0]; cpu < kd_ctrl_page.kdebug_cpus; cpu++, kdbp++) { - - // Find one with raw data - if ((kdsp = kdbp->kd_list_head).raw == KDS_PTR_NULL) - continue; + /* Skip CPUs without data. */ + if ((kdsp = kdbp->kd_list_head).raw == KDS_PTR_NULL) { +next_cpu: + continue; + } /* Debugging aid: maintain a copy of the "kdsp" * index. */ @@ -2691,29 +3590,50 @@ kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) kdsp_shadow = kdsp; - // Get from cpu data to buffer header to buffer + /* From CPU data to buffer header to buffer. */ kdsp_actual = POINTER_FROM_KDS_PTR(kdsp); volatile struct kd_storage *kdsp_actual_shadow; kdsp_actual_shadow = kdsp_actual; - // See if there are actual data left in this buffer + /* Skip buffer if there are no events left. */ rcursor = kdsp_actual->kds_readlast; - if (rcursor == kdsp_actual->kds_bufindx) + if (rcursor == kdsp_actual->kds_bufindx) { continue; + } t = kdbg_get_timestamp(&kdsp_actual->kds_records[rcursor]); - if ((t > barrier) && (barrier > 0)) { - /* - * Need to wait to flush iop again before we - * sort any more data from the buffers - */ + /* Ignore events that have aged out due to wrapping. */ + while (t < barrier_min) { + rcursor = ++kdsp_actual->kds_readlast; + + if (rcursor >= EVENTS_PER_STORAGE_UNIT) { + release_storage_unit(cpu, kdsp.raw); + + if ((kdsp = kdbp->kd_list_head).raw == KDS_PTR_NULL) { + goto next_cpu; + } + kdsp_shadow = kdsp; + kdsp_actual = POINTER_FROM_KDS_PTR(kdsp); + kdsp_actual_shadow = kdsp_actual; + rcursor = kdsp_actual->kds_readlast; + } + + t = kdbg_get_timestamp(&kdsp_actual->kds_records[rcursor]); + } + + if ((t > barrier_max) && (barrier_max > 0)) { + /* + * Need to flush IOPs again before we + * can sort any more data from the + * buffers. + */ out_of_events = TRUE; break; - } + } if (t < kdsp_actual->kds_timestamp) { /* * indicates we've not yet completed filling @@ -2729,8 +3649,8 @@ kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) out_of_events = TRUE; break; } - if (t < mintime) { - mintime = t; + if (t < earliest_time) { + earliest_time = t; min_kdbp = kdbp; min_cpu = cpu; } @@ -2743,21 +3663,10 @@ kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) break; } - // Get data kdsp = min_kdbp->kd_list_head; kdsp_actual = POINTER_FROM_KDS_PTR(kdsp); - if (kdsp_actual->kds_lostevents == TRUE) { - kdbg_set_timestamp_and_cpu(&lostevent, kdsp_actual->kds_records[kdsp_actual->kds_readlast].timestamp, min_cpu); - *tempbuf = lostevent; - - kdsp_actual->kds_lostevents = FALSE; - lostevents = TRUE; - - goto nextevent; - } - - // Copy into buffer + /* Copy earliest event into merged events scratch buffer. */ *tempbuf = kdsp_actual->kds_records[kdsp_actual->kds_readlast++]; if (kdsp_actual->kds_readlast == EVENTS_PER_STORAGE_UNIT) @@ -2765,15 +3674,15 @@ kdbg_read(user_addr_t buffer, size_t *number, vnode_t vp, vfs_context_t ctx) /* * Watch for out of order timestamps - */ - if (mintime < min_kdbp->kd_prev_timebase) { + */ + if (earliest_time < min_kdbp->kd_prev_timebase) { /* * if so, use the previous timestamp + 1 cycle */ min_kdbp->kd_prev_timebase++; kdbg_set_timestamp_and_cpu(tempbuf, min_kdbp->kd_prev_timebase, kdbg_get_cpu(tempbuf)); } else - min_kdbp->kd_prev_timebase = mintime; + min_kdbp->kd_prev_timebase = earliest_time; nextevent: tempbuf_count--; tempbuf_number++; @@ -2783,12 +3692,23 @@ nextevent: break; } if (tempbuf_number) { + if (file_version == RAW_VERSION3) { + if ( !(kdbg_write_v3_event_chunk_header(buffer, V3_RAW_EVENTS, (tempbuf_number * sizeof(kd_buf)), vp, ctx))) { + error = EFAULT; + goto check_error; + } + if (buffer) + buffer += (sizeof(kd_chunk_header_v3) + sizeof(uint64_t)); + assert(count >= (sizeof(kd_chunk_header_v3) + sizeof(uint64_t))); + count -= (sizeof(kd_chunk_header_v3) + sizeof(uint64_t)); + *number += (sizeof(kd_chunk_header_v3) + sizeof(uint64_t)); + } if (vp) { - error = vn_rdwr(UIO_WRITE, vp, (caddr_t)kdcopybuf, tempbuf_number * sizeof(kd_buf), RAW_file_offset, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); - - RAW_file_offset += (tempbuf_number * sizeof(kd_buf)); + size_t write_size = tempbuf_number * sizeof(kd_buf); + error = kdbg_write_to_vnode((caddr_t)kdcopybuf, write_size, vp, ctx, RAW_file_offset); + if (!error) + RAW_file_offset += write_size; if (RAW_file_written >= RAW_FLUSH_SIZE) { cluster_push(vp, 0); @@ -2799,6 +3719,7 @@ nextevent: error = copyout(kdcopybuf, buffer, tempbuf_number * sizeof(kd_buf)); buffer += (tempbuf_number * sizeof(kd_buf)); } +check_error: if (error) { *number = 0; error = EINVAL; @@ -2819,374 +3740,256 @@ nextevent: if ( !(old_kdebug_flags & KDBG_NOWRAP)) { enable_wrap(old_kdebug_slowcheck, lostevents); } + thread_clear_eager_preempt(current_thread()); return (error); } - -unsigned char *getProcName(struct proc *proc); -unsigned char *getProcName(struct proc *proc) { - - return (unsigned char *) &proc->p_comm; /* Return pointer to the proc name */ - -} - -#define STACKSHOT_SUBSYS_LOCK() lck_mtx_lock(&stackshot_subsys_mutex) -#define STACKSHOT_SUBSYS_UNLOCK() lck_mtx_unlock(&stackshot_subsys_mutex) -#if defined(__i386__) || defined (__x86_64__) -#define TRAP_DEBUGGER __asm__ volatile("int3"); -#else -#error No TRAP_DEBUGGER definition for this architecture -#endif - -#define SANE_TRACEBUF_SIZE (8 * 1024 * 1024) -#define SANE_BOOTPROFILE_TRACEBUF_SIZE (64 * 1024 * 1024) - -/* Initialize the mutex governing access to the stack snapshot subsystem */ -__private_extern__ void -stackshot_lock_init( void ) +static int +kdbg_test(void) { - stackshot_subsys_lck_grp_attr = lck_grp_attr_alloc_init(); - - stackshot_subsys_lck_grp = lck_grp_alloc_init("stackshot_subsys_lock", stackshot_subsys_lck_grp_attr); - - stackshot_subsys_lck_attr = lck_attr_alloc_init(); - - lck_mtx_init(&stackshot_subsys_mutex, stackshot_subsys_lck_grp, stackshot_subsys_lck_attr); -} - -/* - * stack_snapshot: Obtains a coherent set of stack traces for all threads - * on the system, tracing both kernel and user stacks - * where available. Uses machine specific trace routines - * for ppc, ppc64 and x86. - * Inputs: uap->pid - process id of process to be traced, or -1 - * for the entire system - * uap->tracebuf - address of the user space destination - * buffer - * uap->tracebuf_size - size of the user space trace buffer - * uap->options - various options, including the maximum - * number of frames to trace. - * Outputs: EPERM if the caller is not privileged - * EINVAL if the supplied trace buffer isn't sanely sized - * ENOMEM if we don't have enough memory to satisfy the - * request - * ENOENT if the target pid isn't found - * ENOSPC if the supplied buffer is insufficient - * *retval contains the number of bytes traced, if successful - * and -1 otherwise. If the request failed due to - * tracebuffer exhaustion, we copyout as much as possible. - */ -int -stack_snapshot(struct proc *p, register struct stack_snapshot_args *uap, int32_t *retval) { - int error = 0; +#define KDEBUG_TEST_CODE(code) BSDDBG_CODE(DBG_BSD_KDEBUG_TEST, (code)) + int code = 0; + + KDBG(KDEBUG_TEST_CODE(code)); code++; + KDBG(KDEBUG_TEST_CODE(code), 1); code++; + KDBG(KDEBUG_TEST_CODE(code), 1, 2); code++; + KDBG(KDEBUG_TEST_CODE(code), 1, 2, 3); code++; + KDBG(KDEBUG_TEST_CODE(code), 1, 2, 3, 4); code++; + + KDBG_RELEASE(KDEBUG_TEST_CODE(code)); code++; + KDBG_RELEASE(KDEBUG_TEST_CODE(code), 1); code++; + KDBG_RELEASE(KDEBUG_TEST_CODE(code), 1, 2); code++; + KDBG_RELEASE(KDEBUG_TEST_CODE(code), 1, 2, 3); code++; + KDBG_RELEASE(KDEBUG_TEST_CODE(code), 1, 2, 3, 4); code++; + + KDBG_FILTERED(KDEBUG_TEST_CODE(code)); code++; + KDBG_FILTERED(KDEBUG_TEST_CODE(code), 1); code++; + KDBG_FILTERED(KDEBUG_TEST_CODE(code), 1, 2); code++; + KDBG_FILTERED(KDEBUG_TEST_CODE(code), 1, 2, 3); code++; + KDBG_FILTERED(KDEBUG_TEST_CODE(code), 1, 2, 3, 4); code++; + + KDBG_DEBUG(KDEBUG_TEST_CODE(code)); code++; + KDBG_DEBUG(KDEBUG_TEST_CODE(code), 1); code++; + KDBG_DEBUG(KDEBUG_TEST_CODE(code), 1, 2); code++; + KDBG_DEBUG(KDEBUG_TEST_CODE(code), 1, 2, 3); code++; + KDBG_DEBUG(KDEBUG_TEST_CODE(code), 1, 2, 3, 4); code++; - if ((error = suser(kauth_cred_get(), &p->p_acflag))) - return(error); - - return stack_snapshot2(uap->pid, uap->tracebuf, uap->tracebuf_size, - uap->flags, uap->dispatch_offset, retval); + return 0; +#undef KDEBUG_TEST_CODE } -int -stack_snapshot_from_kernel(pid_t pid, void *buf, uint32_t size, uint32_t flags, unsigned *bytesTraced) +void +kdebug_boot_trace(unsigned int n_events, char *filter_desc) { - int error = 0; - boolean_t istate; - - if ((buf == NULL) || (size <= 0) || (bytesTraced == NULL)) { - return -1; + assert(filter_desc != NULL); + +#if (defined(__i386__) || defined(__x86_64__)) + /* only trace MACH events when outputting kdebug to serial */ + if (kdebug_serial) { + n_events = 1; + if (filter_desc[0] == '\0') { + filter_desc[0] = 'C'; + filter_desc[1] = '1'; + filter_desc[2] = '\0'; + } } +#endif - /* cap in individual stackshot to SANE_TRACEBUF_SIZE */ - if (size > SANE_TRACEBUF_SIZE) { - size = SANE_TRACEBUF_SIZE; + if (log_leaks && n_events == 0) { + n_events = 200000; } -/* Serialize tracing */ - STACKSHOT_SUBSYS_LOCK(); - istate = ml_set_interrupts_enabled(FALSE); - - -/* Preload trace parameters*/ - kdp_snapshot_preflight(pid, buf, size, flags, 0); - -/* Trap to the debugger to obtain a coherent stack snapshot; this populates - * the trace buffer - */ - TRAP_DEBUGGER; - - ml_set_interrupts_enabled(istate); - - *bytesTraced = kdp_stack_snapshot_bytes_traced(); - - error = kdp_stack_snapshot_geterror(); - - STACKSHOT_SUBSYS_UNLOCK(); - - return error; - + kdebug_trace_start(n_events, filter_desc, FALSE); } -int -stack_snapshot2(pid_t pid, user_addr_t tracebuf, uint32_t tracebuf_size, uint32_t flags, uint32_t dispatch_offset, int32_t *retval) +static void +kdbg_set_typefilter_string(const char *filter_desc) { - boolean_t istate; - int error = 0; - unsigned bytesTraced = 0; - -#if CONFIG_TELEMETRY - if (flags & STACKSHOT_GLOBAL_MICROSTACKSHOT_ENABLE) { - telemetry_global_ctl(1); - *retval = 0; - return (0); - } else if (flags & STACKSHOT_GLOBAL_MICROSTACKSHOT_DISABLE) { - telemetry_global_ctl(0); - *retval = 0; - return (0); - } + char *end = NULL; - if (flags & STACKSHOT_WINDOWED_MICROSTACKSHOTS_ENABLE) { - error = telemetry_enable_window(); - - if (error != KERN_SUCCESS) { - /* We are probably out of memory */ - *retval = -1; - return ENOMEM; - } - - *retval = 0; - return (0); - } else if (flags & STACKSHOT_WINDOWED_MICROSTACKSHOTS_DISABLE) { - telemetry_disable_window(); - *retval = 0; - return (0); - } -#endif - - *retval = -1; -/* Serialize tracing */ - STACKSHOT_SUBSYS_LOCK(); - - if (tracebuf_size <= 0) { - error = EINVAL; - goto error_exit; - } + lck_mtx_assert(ktrace_lock, LCK_MTX_ASSERT_OWNED); -#if CONFIG_TELEMETRY - if (flags & STACKSHOT_GET_MICROSTACKSHOT) { + assert(filter_desc != NULL); - if (tracebuf_size > SANE_TRACEBUF_SIZE) { - error = EINVAL; - goto error_exit; - } + typefilter_reject_all(kdbg_typefilter); + typefilter_allow_class(kdbg_typefilter, DBG_TRACE); - bytesTraced = tracebuf_size; - error = telemetry_gather(tracebuf, &bytesTraced, - (flags & STACKSHOT_SET_MICROSTACKSHOT_MARK) ? TRUE : FALSE); - if (error == KERN_NO_SPACE) { - error = ENOSPC; + /* if the filter description starts with a number, assume it's a csc */ + if (filter_desc[0] >= '0' && filter_desc[0] <= '9'){ + unsigned long csc = strtoul(filter_desc, NULL, 0); + if (filter_desc != end && csc <= KDBG_CSC_MAX) { + typefilter_allow_csc(kdbg_typefilter, csc); } - - *retval = (int)bytesTraced; - goto error_exit; + return; } - if (flags & STACKSHOT_GET_WINDOWED_MICROSTACKSHOTS) { + while (filter_desc[0] != '\0') { + unsigned long allow_value; - if (tracebuf_size > SANE_TRACEBUF_SIZE) { - error = EINVAL; - goto error_exit; + char filter_type = filter_desc[0]; + if (filter_type != 'C' && filter_type != 'S') { + return; } + filter_desc++; - bytesTraced = tracebuf_size; - error = telemetry_gather_windowed(tracebuf, &bytesTraced); - if (error == KERN_NO_SPACE) { - error = ENOSPC; + allow_value = strtoul(filter_desc, &end, 0); + if (filter_desc == end) { + /* cannot parse as integer */ + return; } - *retval = (int)bytesTraced; - goto error_exit; - } - - if (flags & STACKSHOT_GET_BOOT_PROFILE) { - - if (tracebuf_size > SANE_BOOTPROFILE_TRACEBUF_SIZE) { - error = EINVAL; - goto error_exit; + switch (filter_type) { + case 'C': + if (allow_value <= KDBG_CLASS_MAX) { + typefilter_allow_class(kdbg_typefilter, allow_value); + } else { + /* illegal class */ + return; + } + break; + case 'S': + if (allow_value <= KDBG_CSC_MAX) { + typefilter_allow_csc(kdbg_typefilter, allow_value); + } else { + /* illegal class subclass */ + return; + } + break; + default: + return; } - bytesTraced = tracebuf_size; - error = bootprofile_gather(tracebuf, &bytesTraced); - if (error == KERN_NO_SPACE) { - error = ENOSPC; + /* advance to next filter entry */ + filter_desc = end; + if (filter_desc[0] == ',') { + filter_desc++; } - - *retval = (int)bytesTraced; - goto error_exit; - } -#endif - - if (tracebuf_size > SANE_TRACEBUF_SIZE) { - error = EINVAL; - goto error_exit; } +} - assert(stackshot_snapbuf == NULL); - if (kmem_alloc_kobject(kernel_map, (vm_offset_t *)&stackshot_snapbuf, tracebuf_size) != KERN_SUCCESS) { - error = ENOMEM; - goto error_exit; - } +/* + * This function is meant to be called from the bootstrap thread or coming out + * of acpi_idle_kernel. + */ +void +kdebug_trace_start(unsigned int n_events, const char *filter_desc, + boolean_t need_map) +{ + uint32_t old1, old2; - if (panic_active()) { - error = ENOMEM; - goto error_exit; + if (!n_events) { + return; } - istate = ml_set_interrupts_enabled(FALSE); -/* Preload trace parameters*/ - kdp_snapshot_preflight(pid, stackshot_snapbuf, tracebuf_size, flags, dispatch_offset); + lck_mtx_lock(ktrace_lock); -/* Trap to the debugger to obtain a coherent stack snapshot; this populates - * the trace buffer - */ + kdbg_lock_init(); - TRAP_DEBUGGER; + ktrace_kernel_configure(KTRACE_KDEBUG); - ml_set_interrupts_enabled(istate); + kdbg_set_nkdbufs(n_events); - bytesTraced = kdp_stack_snapshot_bytes_traced(); - - if (bytesTraced > 0) { - if ((error = copyout(stackshot_snapbuf, tracebuf, - ((bytesTraced < tracebuf_size) ? - bytesTraced : tracebuf_size)))) - goto error_exit; - *retval = bytesTraced; - } - else { - error = ENOENT; - goto error_exit; - } + kernel_debug_string_early("start_kern_tracing"); - error = kdp_stack_snapshot_geterror(); - if (error == -1) { - error = ENOSPC; - *retval = -1; - goto error_exit; + if (kdbg_reinit(TRUE)) { + printf("error from kdbg_reinit, kernel tracing not started\n"); + goto out; } -error_exit: - if (stackshot_snapbuf != NULL) - kmem_free(kernel_map, (vm_offset_t) stackshot_snapbuf, tracebuf_size); - stackshot_snapbuf = NULL; - STACKSHOT_SUBSYS_UNLOCK(); - return error; -} - -void -start_kern_tracing(unsigned int new_nkdbufs, boolean_t need_map) -{ - - if (!new_nkdbufs) - return; - nkdbufs = kdbg_set_nkdbufs(new_nkdbufs); - kdbg_lock_init(); - - kernel_debug_string("start_kern_tracing"); + /* + * Wrapping is disabled because boot and wake tracing is interested in + * the earliest events, at the expense of later ones. + */ + (void)disable_wrap(&old1, &old2); - if (0 == kdbg_reinit(TRUE)) { + if (filter_desc && filter_desc[0] != '\0') { + if (kdbg_initialize_typefilter(NULL) == KERN_SUCCESS) { + kdbg_set_typefilter_string(filter_desc); + kdbg_enable_typefilter(); + } + } - if (need_map == TRUE) { - uint32_t old1, old2; + /* + * Hold off interrupts between getting a thread map and enabling trace + * and until the early traces are recorded. + */ + boolean_t s = ml_set_interrupts_enabled(FALSE); - kdbg_thrmap_init(); + if (need_map == TRUE) { + kdbg_thrmap_init(); + } - disable_wrap(&old1, &old2); - } + kdbg_set_tracing_enabled(TRUE, kdebug_serial ? + (KDEBUG_ENABLE_TRACE | KDEBUG_ENABLE_SERIAL) : + KDEBUG_ENABLE_TRACE); - /* Hold off interrupts until the early traces are cut */ - boolean_t s = ml_set_interrupts_enabled(FALSE); + /* + * Transfer all very early events from the static buffer into the real + * buffers. + */ + kernel_debug_early_end(); - kdbg_set_tracing_enabled(TRUE, KDEBUG_ENABLE_TRACE); + ml_set_interrupts_enabled(s); - /* - * Transfer all very early events from the static buffer - * into the real buffers. - */ - kernel_debug_early_end(); - - ml_set_interrupts_enabled(s); + printf("kernel tracing started with %u events\n", n_events); - printf("kernel tracing started\n"); - } else { - printf("error from kdbg_reinit,kernel tracing not started\n"); +#if KDEBUG_MOJO_TRACE + if (kdebug_serial) { + printf("serial output enabled with %lu named events\n", + sizeof(kd_events)/sizeof(kd_event_t)); } -} - -void -start_kern_tracing_with_typefilter(unsigned int new_nkdbufs, - boolean_t need_map, - unsigned int typefilter) -{ - /* startup tracing */ - start_kern_tracing(new_nkdbufs, need_map); - - /* check that tracing was actually enabled */ - if (!(kdebug_enable & KDEBUG_ENABLE_TRACE)) - return; +#endif - /* setup the typefiltering */ - if (0 == kdbg_enable_typefilter()) - setbit(type_filter_bitmap, typefilter & (CSC_MASK >> CSC_OFFSET)); +out: + lck_mtx_unlock(ktrace_lock); } void kdbg_dump_trace_to_file(const char *filename) { - vfs_context_t ctx; - vnode_t vp; - int error; - size_t number; + vfs_context_t ctx; + vnode_t vp; + size_t write_size; + lck_mtx_lock(ktrace_lock); - if ( !(kdebug_enable & KDEBUG_ENABLE_TRACE)) - return; + if (!(kdebug_enable & KDEBUG_ENABLE_TRACE)) { + goto out; + } - if (global_state_pid != -1) { - if ((proc_find(global_state_pid)) != NULL) { - /* - * The global pid exists, we're running - * due to fs_usage, latency, etc... - * don't cut the panic/shutdown trace file - * Disable tracing from this point to avoid - * perturbing state. - */ - kdebug_enable = 0; - kd_ctrl_page.enabled = 0; - commpage_update_kdebug_enable(); - return; - } + if (ktrace_get_owning_pid() != 0) { + /* + * Another process owns ktrace and is still active, disable tracing to + * capture whatever was being recorded. + */ + kdebug_enable = 0; + kd_ctrl_page.enabled = 0; + commpage_update_kdebug_state(); + goto out; } - KERNEL_DEBUG_CONSTANT((TRACEDBG_CODE(DBG_TRACE_INFO, 0)) | DBG_FUNC_NONE, 0, 0, 0, 0, 0); + + KERNEL_DEBUG_CONSTANT(TRACE_PANIC | DBG_FUNC_NONE, 0, 0, 0, 0, 0); kdebug_enable = 0; kd_ctrl_page.enabled = 0; - commpage_update_kdebug_enable(); + commpage_update_kdebug_state(); ctx = vfs_context_kernel(); - if ((error = vnode_open(filename, (O_CREAT | FWRITE | O_NOFOLLOW), 0600, 0, &vp, ctx))) - return; + if (vnode_open(filename, (O_CREAT | FWRITE | O_NOFOLLOW), 0600, 0, &vp, ctx)) { + goto out; + } - number = kd_mapcount * sizeof(kd_threadmap); - kdbg_readthrmap(0, &number, vp, ctx); + kdbg_write_thread_map(vp, ctx); - number = nkdbufs*sizeof(kd_buf); - kdbg_read(0, &number, vp, ctx); - - vnode_close(vp, FWRITE, ctx); + write_size = nkdbufs * sizeof(kd_buf); + kdbg_read(0, &write_size, vp, ctx, RAW_VERSION1); + vnode_close(vp, FWRITE, ctx); sync(current_proc(), (void *)NULL, (int *)NULL); + +out: + lck_mtx_unlock(ktrace_lock); } /* Helper function for filling in the BSD name for an address space @@ -3209,3 +4012,147 @@ void kdbg_get_task_name(char* name_buf, int len, task_t task) else snprintf(name_buf, len, "%p [!bsd]", task); } + +#if KDEBUG_MOJO_TRACE +static kd_event_t * +binary_search(uint32_t id) +{ + int low, high, mid; + + low = 0; + high = sizeof(kd_events)/sizeof(kd_event_t) - 1; + + while (TRUE) + { + mid = (low + high) / 2; + + if (low > high) + return NULL; /* failed */ + else if ( low + 1 >= high) { + /* We have a match */ + if (kd_events[high].id == id) + return &kd_events[high]; + else if (kd_events[low].id == id) + return &kd_events[low]; + else + return NULL; /* search failed */ + } + else if (id < kd_events[mid].id) + high = mid; + else + low = mid; + } +} + +/* + * Look up event id to get name string. + * Using a per-cpu cache of a single entry + * before resorting to a binary search of the full table. + */ +#define NCACHE 1 +static kd_event_t *last_hit[MAX_CPUS]; +static kd_event_t * +event_lookup_cache(uint32_t cpu, uint32_t id) +{ + if (last_hit[cpu] == NULL || last_hit[cpu]->id != id) + last_hit[cpu] = binary_search(id); + return last_hit[cpu]; +} + +static uint64_t kd_last_timstamp; + +static void +kdebug_serial_print( + uint32_t cpunum, + uint32_t debugid, + uint64_t timestamp, + uintptr_t arg1, + uintptr_t arg2, + uintptr_t arg3, + uintptr_t arg4, + uintptr_t threadid + ) +{ + char kprintf_line[192]; + char event[40]; + uint64_t us = timestamp / NSEC_PER_USEC; + uint64_t us_tenth = (timestamp % NSEC_PER_USEC) / 100; + uint64_t delta = timestamp - kd_last_timstamp; + uint64_t delta_us = delta / NSEC_PER_USEC; + uint64_t delta_us_tenth = (delta % NSEC_PER_USEC) / 100; + uint32_t event_id = debugid & KDBG_EVENTID_MASK; + const char *command; + const char *bra; + const char *ket; + kd_event_t *ep; + + /* event time and delta from last */ + snprintf(kprintf_line, sizeof(kprintf_line), + "%11llu.%1llu %8llu.%1llu ", + us, us_tenth, delta_us, delta_us_tenth); + + + /* event (id or name) - start prefixed by "[", end postfixed by "]" */ + bra = (debugid & DBG_FUNC_START) ? "[" : " "; + ket = (debugid & DBG_FUNC_END) ? "]" : " "; + ep = event_lookup_cache(cpunum, event_id); + if (ep) { + if (strlen(ep->name) < sizeof(event) - 3) + snprintf(event, sizeof(event), "%s%s%s", + bra, ep->name, ket); + else + snprintf(event, sizeof(event), "%s%x(name too long)%s", + bra, event_id, ket); + } else { + snprintf(event, sizeof(event), "%s%x%s", + bra, event_id, ket); + } + snprintf(kprintf_line + strlen(kprintf_line), + sizeof(kprintf_line) - strlen(kprintf_line), + "%-40s ", event); + + /* arg1 .. arg4 with special cases for strings */ + switch (event_id) { + case VFS_LOOKUP: + case VFS_LOOKUP_DONE: + if (debugid & DBG_FUNC_START) { + /* arg1 hex then arg2..arg4 chars */ + snprintf(kprintf_line + strlen(kprintf_line), + sizeof(kprintf_line) - strlen(kprintf_line), + "%-16lx %-8s%-8s%-8s ", + arg1, (char*)&arg2, (char*)&arg3, (char*)&arg4); + break; + } + /* else fall through for arg1..arg4 chars */ + case TRACE_STRING_EXEC: + case TRACE_STRING_NEWTHREAD: + case TRACE_INFO_STRING: + snprintf(kprintf_line + strlen(kprintf_line), + sizeof(kprintf_line) - strlen(kprintf_line), + "%-8s%-8s%-8s%-8s ", + (char*)&arg1, (char*)&arg2, (char*)&arg3, (char*)&arg4); + break; + default: + snprintf(kprintf_line + strlen(kprintf_line), + sizeof(kprintf_line) - strlen(kprintf_line), + "%-16lx %-16lx %-16lx %-16lx", + arg1, arg2, arg3, arg4); + } + + /* threadid, cpu and command name */ + if (threadid == (uintptr_t)thread_tid(current_thread()) && + current_proc() && + current_proc()->p_comm[0]) + command = current_proc()->p_comm; + else + command = "-"; + snprintf(kprintf_line + strlen(kprintf_line), + sizeof(kprintf_line) - strlen(kprintf_line), + " %-16lx %-2d %s\n", + threadid, cpunum, command); + + kprintf("%s", kprintf_line); + kd_last_timstamp = timestamp; +} + +#endif