#include <machine/pal_routines.h>
+extern boolean_t kdebug_serial;
+#if KDEBUG_MOJO_TRACE
+#include <sys/kdebugevents.h>
+static void kdebug_serial_print( /* forward */
+ uint32_t, uint32_t, uint64_t,
+ uintptr_t, uintptr_t, uintptr_t, uintptr_t, uintptr_t);
+#endif
+
/*
* IOP(s)
*
/* XXX should have prototypes, but Mach does not provide one */
void task_act_iterate_wth_args(task_t, void(*)(thread_t, void *), void *);
int cpu_number(void); /* XXX <machine/...> include path broken */
+void commpage_update_kdebug_enable(void); /* XXX sign */
/* XXX should probably be static, but it's debugging code... */
int kdbg_read(user_addr_t, size_t *, vnode_t, vfs_context_t);
#define MACH_SysCall 0x010c0000
#define DBG_SCALL_MASK 0xffff0000
-
/* task to string structure */
struct tts
{
{
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();
} 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();
}
lck_spin_unlock(kds_spin_lock);
ml_set_interrupts_enabled(s);
if (kdbp_vict == NULL) {
kdebug_enable = 0;
kd_ctrl_page.enabled = 0;
+ commpage_update_kdebug_enable();
retval = FALSE;
goto out;
}
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;
-void
-kernel_debug_internal(
- uint32_t debugid,
- uintptr_t arg1,
- uintptr_t arg2,
- uintptr_t arg3,
- uintptr_t arg4,
- uintptr_t arg5);
-
-__attribute__((always_inline)) void
+static void
kernel_debug_internal(
uint32_t debugid,
uintptr_t arg1,
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;
/* Stuff the message string in the args and log it. */
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]);
}
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;
}
/*
- * 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.
*/
/* 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,
/* 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");
}
/*
- * Support syscall SYS_kdebug_trace
+ * Support syscall SYS_kdebug_trace. U64->K32 args may get truncated in kdebug_trace64
*/
int
-kdebug_trace(__unused struct proc *p, struct kdebug_trace_args *uap, __unused int32_t *retval)
+kdebug_trace(struct proc *p, struct kdebug_trace_args *uap, int32_t *retval)
+{
+ struct kdebug_trace64_args uap64;
+
+ uap64.code = uap->code;
+ uap64.arg1 = uap->arg1;
+ uap64.arg2 = uap->arg2;
+ uap64.arg3 = uap->arg3;
+ uap64.arg4 = uap->arg4;
+
+ return kdebug_trace64(p, &uap64, retval);
+}
+
+/*
+ * Support syscall SYS_kdebug_trace64. 64-bit args on K32 will get truncated to fit in 32-bit record format.
+ */
+int kdebug_trace64(__unused struct proc *p, struct kdebug_trace64_args *uap, __unused int32_t *retval)
{
+ uint8_t code_class;
+
+ /*
+ * Not all class are supported for injection from userspace, especially ones used by the core
+ * kernel tracing infrastructure.
+ */
+ code_class = EXTRACT_CLASS(uap->code);
+
+ switch (code_class) {
+ case DBG_TRACE:
+ return EPERM;
+ }
+
if ( __probable(kdebug_enable == 0) )
- return(0);
-
- kernel_debug_internal(uap->code, uap->arg1, uap->arg2, uap->arg3, uap->arg4, (uintptr_t)thread_tid(current_thread()));
+ 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()));
return(0);
}
-
static void
kdbg_lock_init(void)
{
if (name[0] == KERN_KDWRITETR) {
number = nkdbufs * sizeof(kd_buf);
- KERNEL_DEBUG_CONSTANT((TRACEDBG_CODE(DBG_TRACE_INFO, 3)) | DBG_FUNC_START, 0, 0, 0, 0, 0);
+ KERNEL_DEBUG_CONSTANT(TRACE_WRITING_EVENTS | 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_END, number, 0, 0, 0, 0);
*sizep = number;
} else {
return EINVAL;
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
/* Hold off interrupts until the early traces are cut */
boolean_t s = ml_set_interrupts_enabled(FALSE);
- kdbg_set_tracing_enabled(TRUE, KDEBUG_ENABLE_TRACE);
+ kdbg_set_tracing_enabled(
+ TRUE,
+ kdebug_serial ?
+ (KDEBUG_ENABLE_TRACE | KDEBUG_ENABLE_SERIAL) :
+ KDEBUG_ENABLE_TRACE);
/*
* Transfer all very early events from the static buffer
ml_set_interrupts_enabled(s);
printf("kernel tracing 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));
+ }
+#endif
} else {
- printf("error from kdbg_reinit,kernel tracing not started\n");
+ printf("error from kdbg_reinit, kernel tracing not started\n");
}
}
*/
kdebug_enable = 0;
kd_ctrl_page.enabled = 0;
+ commpage_update_kdebug_enable();
return;
}
}
- 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();
ctx = vfs_context_kernel();
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 & DBG_FUNC_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)
+ 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
projects / apple / xnu.git / blobdiff