[misc] convert various low level printfs to kprintf

Also generally remove boot spew and print a note about the git
repository.

app/app.c

@@ -23,6 +23,7 @@
 #include <stdio.h>
 #include <app.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 
 extern const struct app_descriptor __apps_start;
 extern const struct app_descriptor __apps_end;

arch/arm/arm-m/exceptions.c

@@ -25,28 +25,29 @@
 #include <compiler.h>
 #include <stdint.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 #include <arch/arm/cm.h>
 
 static void dump_frame(const struct arm_cm_exception_frame *frame)
 {
-	printf("exception frame at %p\n", frame);
-	printf("\tr0  0x%08x r1  0x%08x r2  0x%08x r3 0x%08x r4 0x%08x\n",
+	kprintf("exception frame at %p\n", frame);
+	kprintf("\tr0  0x%08x r1  0x%08x r2  0x%08x r3 0x%08x r4 0x%08x\n",
 	       frame->r0, frame->r1, frame->r2, frame->r3, frame->r4);
-	printf("\tr5  0x%08x r6  0x%08x r7  0x%08x r8 0x%08x r9 0x%08x\n",
+	kprintf("\tr5  0x%08x r6  0x%08x r7  0x%08x r8 0x%08x r9 0x%08x\n",
 	       frame->r5, frame->r6, frame->r7, frame->r8, frame->r9);
-	printf("\tr10 0x%08x r11 0x%08x r12 0x%08x\n",
+	kprintf("\tr10 0x%08x r11 0x%08x r12 0x%08x\n",
 	       frame->r10, frame->r11, frame->r12);
-	printf("\tlr  0x%08x pc  0x%08x psr 0x%08x\n",
+	kprintf("\tlr  0x%08x pc  0x%08x psr 0x%08x\n",
 	       frame->lr, frame->pc, frame->psr);
 }
 
 static void hardfault(struct arm_cm_exception_frame *frame)
 {
 	inc_critical_section();
-	printf("hardfault: ");
+	kprintf("hardfault: ");
 	dump_frame(frame);
 
-	printf("HFSR 0x%x\n", SCB->HFSR);
+	kprintf("HFSR 0x%x\n", SCB->HFSR);
 
 	halt();
 }
@@ -54,7 +55,7 @@ static void hardfault(struct arm_cm_exception_frame *frame)
 static void usagefault(struct arm_cm_exception_frame *frame)
 {
 	inc_critical_section();
-	printf("usagefault: ");
+	kprintf("usagefault: ");
 	dump_frame(frame);
 
 	halt();
@@ -63,7 +64,7 @@ static void usagefault(struct arm_cm_exception_frame *frame)
 static void busfault(struct arm_cm_exception_frame *frame)
 {
 	inc_critical_section();
-	printf("busfault: ");
+	kprintf("busfault: ");
 	dump_frame(frame);
 
 	halt();
@@ -74,7 +75,7 @@ static void busfault(struct arm_cm_exception_frame *frame)
 void _nmi(void)
 {
 	inc_critical_section();
-	printf("nmi\n");
+	kprintf("nmi\n");
 	halt();
 }
 
@@ -92,7 +93,7 @@ __NAKED void _hardfault(void)
 void _memmanage(void)
 {
 	inc_critical_section();
-	printf("memmanage\n");
+	kprintf("memmanage\n");
 	halt();
 }
 
@@ -122,7 +123,7 @@ void _usagefault(void)
 void __WEAK _systick(void)
 {
 	inc_critical_section();
-	printf("systick\n");
+	kprintf("systick\n");
 	halt();
 }
 

arch/arm/arm-m/systick.c

@@ -29,8 +29,6 @@
 #include <arch/arm.h>
 #include <arch/arm/cm.h>
 
-#define LOCAL_TRACE 0
-
 void arm_cm_systick_init(void)
 {
 	NVIC_SetPriority(SysTick_IRQn, arm_cm_medium_priority());
@@ -38,10 +36,7 @@ void arm_cm_systick_init(void)
 
 void arm_cm_systick_set_periodic(uint32_t systick_clk_freq, lk_time_t period)
 {
-	LTRACEF("clk_freq %u, period %u\n", systick_clk_freq, (uint)period);
-
 	uint32_t ticks = systick_clk_freq / (1000 / period);
-	LTRACEF("ticks %d\n", ticks);
 
 	SysTick->LOAD = (ticks & SysTick_LOAD_RELOAD_Msk) - 1;
 	SysTick->VAL = 0;

arch/arm/arm-m/thread.c

@@ -49,7 +49,7 @@ static void initial_thread_func(void)
 {
 	int ret;
 
-	LTRACEF("thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
+	KLTRACEF("thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
 #if LOCAL_TRACE
 	dump_thread(current_thread);
 #endif
@@ -59,14 +59,14 @@ static void initial_thread_func(void)
 
 	ret = current_thread->entry(current_thread->arg);
 
-	LTRACEF("thread %p exiting with %d\n", current_thread, ret);
+	KLTRACEF("thread %p exiting with %d\n", current_thread, ret);
 
 	thread_exit(ret);
 }
 
 void arch_thread_initialize(struct thread *t)
 {
-	LTRACEF("thread %p, stack %p\n", t, t->stack);
+	KLTRACEF("thread %p, stack %p\n", t, t->stack);
 
 	/* find the top of the stack and align it on an 8 byte boundary */
 	uint32_t *sp = (void *)ROUNDDOWN((vaddr_t)t->stack + t->stack_size, 8);
@@ -90,13 +90,13 @@ static void pendsv(struct arm_cm_exception_frame_long *frame)
 
 	ASSERT(critical_section_count == 1);
 
-	LTRACEF("preempting thread %p (%s)\n", current_thread, current_thread->name);
+	KLTRACEF("preempting thread %p (%s)\n", current_thread, current_thread->name);
 
 	/* save the iframe the pendsv fired on and hit the preemption code */
 	preempt_frame = frame;
 	thread_preempt();
 
-	LTRACEF("fell through\n");
+	KLTRACEF("fell through\n");
 
 	/* if we got here, there wasn't anything to switch to, so just fall through and exit */
 	preempt_frame = NULL;
@@ -185,7 +185,7 @@ __NAKED static void _thread_mode_bounce(void)
  */
 void arch_context_switch(struct thread *oldthread, struct thread *newthread)
 {
-	LTRACE_ENTRY;
+	KLTRACE_ENTRY;
 
 	if (newthread->arch.was_preempted) {
 		/* we're about to return directly to a thread that was preempted (in user space),
@@ -200,7 +200,7 @@ void arch_context_switch(struct thread *oldthread, struct thread *newthread)
 		oldthread->arch.sp = (addr_t)preempt_frame;
 		preempt_frame = NULL;
 
-		LTRACEF("we're preempted, new %d\n", newthread->arch.was_preempted);
+		KLTRACEF("we're preempted, new %d\n", newthread->arch.was_preempted);
 		if (newthread->arch.was_preempted) {
 			/* return directly to the preempted thread's iframe */
 			__asm__ volatile(
@@ -222,7 +222,7 @@ void arch_context_switch(struct thread *oldthread, struct thread *newthread)
 			frame->psr = (1 << 24); /* thread bit set, IPSR 0 */
 			frame->r0 = frame->r1 =  frame->r2 = frame->r3 = frame->r12 = frame->lr = 99;
 
-			LTRACEF("iretting to user space\n");
+			KLTRACEF("iretting to user space\n");
 			//hexdump(frame, sizeof(*frame) + 64);
 
 			__asm__ volatile(
@@ -237,7 +237,7 @@ void arch_context_switch(struct thread *oldthread, struct thread *newthread)
 		oldthread->arch.was_preempted = false;
 
 		if (newthread->arch.was_preempted) {
-			LTRACEF("not being preempted, but switching to preempted thread\n");
+			KLTRACEF("not being preempted, but switching to preempted thread\n");
 			_half_save_and_svc(&oldthread->arch.sp, newthread->arch.sp);
 		} else {
 			/* fast path, both sides did not preempt */

arch/arm/arm/faults.c

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008 Travis Geiselbrecht
+ * Copyright (c) 2008-2013 Travis Geiselbrecht
  *
  * Permission is hereby granted, free of charge, to any person obtaining
  * a copy of this software and associated documentation files
@@ -23,23 +23,24 @@
 #include <debug.h>
 #include <arch/arm.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 
 static void dump_fault_frame(struct arm_fault_frame *frame)
 {
-	dprintf(CRITICAL, "r0  0x%08x r1  0x%08x r2  0x%08x r3  0x%08x\n", frame->r[0], frame->r[1], frame->r[2], frame->r[3]);
-	dprintf(CRITICAL, "r4  0x%08x r5  0x%08x r6  0x%08x r7  0x%08x\n", frame->r[4], frame->r[5], frame->r[6], frame->r[7]);
-	dprintf(CRITICAL, "r8  0x%08x r9  0x%08x r10 0x%08x r11 0x%08x\n", frame->r[8], frame->r[9], frame->r[10], frame->r[11]);
-	dprintf(CRITICAL, "r12 0x%08x usp 0x%08x ulr 0x%08x pc  0x%08x\n", frame->r[12], frame->usp, frame->ulr, frame->pc);
-	dprintf(CRITICAL, "spsr 0x%08x\n", frame->spsr);
+	kprintf("r0  0x%08x r1  0x%08x r2  0x%08x r3  0x%08x\n", frame->r[0], frame->r[1], frame->r[2], frame->r[3]);
+	kprintf("r4  0x%08x r5  0x%08x r6  0x%08x r7  0x%08x\n", frame->r[4], frame->r[5], frame->r[6], frame->r[7]);
+	kprintf("r8  0x%08x r9  0x%08x r10 0x%08x r11 0x%08x\n", frame->r[8], frame->r[9], frame->r[10], frame->r[11]);
+	kprintf("r12 0x%08x usp 0x%08x ulr 0x%08x pc  0x%08x\n", frame->r[12], frame->usp, frame->ulr, frame->pc);
+	kprintf("spsr 0x%08x\n", frame->spsr);
 
 	struct arm_mode_regs regs;
 	arm_save_mode_regs(&regs);
 
-	dprintf(CRITICAL, "%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_FIQ) ? '*' : ' ', "fiq", regs.fiq_r13, regs.fiq_r14);
-	dprintf(CRITICAL, "%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_IRQ) ? '*' : ' ', "irq", regs.irq_r13, regs.irq_r14);
-	dprintf(CRITICAL, "%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_SVC) ? '*' : ' ', "svc", regs.svc_r13, regs.svc_r14);
-	dprintf(CRITICAL, "%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_UND) ? '*' : ' ', "und", regs.und_r13, regs.und_r14);
-	dprintf(CRITICAL, "%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_SYS) ? '*' : ' ', "sys", regs.sys_r13, regs.sys_r14);
+	kprintf("%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_FIQ) ? '*' : ' ', "fiq", regs.fiq_r13, regs.fiq_r14);
+	kprintf("%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_IRQ) ? '*' : ' ', "irq", regs.irq_r13, regs.irq_r14);
+	kprintf("%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_SVC) ? '*' : ' ', "svc", regs.svc_r13, regs.svc_r14);
+	kprintf("%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_UND) ? '*' : ' ', "und", regs.und_r13, regs.und_r14);
+	kprintf("%c%s r13 0x%08x r14 0x%08x\n", ((frame->spsr & MODE_MASK) == MODE_SYS) ? '*' : ' ', "sys", regs.sys_r13, regs.sys_r14);
 
 	// dump the bottom of the current stack
 	addr_t stack;
@@ -64,7 +65,7 @@ static void dump_fault_frame(struct arm_fault_frame *frame)
 	}
 
 	if (stack != 0) {
-		dprintf(CRITICAL, "bottom of stack at 0x%08x:\n", (unsigned int)stack);
+		kprintf("bottom of stack at 0x%08x:\n", (unsigned int)stack);
 		hexdump((void *)stack, 128);
 	}
 }
@@ -73,7 +74,7 @@ static void exception_die(struct arm_fault_frame *frame, int pc_off, const char
 {
 	inc_critical_section();
 	frame->pc += pc_off;
-	dprintf(CRITICAL, msg);
+	kprintf(msg);
 	dump_fault_frame(frame);
 
 	halt();

arch/arm/arm/thread.c

@@ -25,6 +25,7 @@
 #include <stdlib.h>
 #include <debug.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 #include <arch/arm.h>
 
 struct context_switch_frame {
@@ -46,7 +47,7 @@ static void initial_thread_func(void)
 {
 	int ret;
 
-//	dprintf("initial_thread_func: thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
+//	kprintf("initial_thread_func: thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
 //	dump_thread(current_thread);
 
 	/* exit the implicit critical section we're within */
@@ -54,7 +55,7 @@ static void initial_thread_func(void)
 
 	ret = current_thread->entry(current_thread->arg);
 
-//	dprintf("initial_thread_func: thread %p exiting with %d\n", current_thread, ret);
+//	kprintf("initial_thread_func: thread %p exiting with %d\n", current_thread, ret);
 
 	thread_exit(ret);
 }
@@ -80,7 +81,7 @@ void arch_thread_initialize(thread_t *t)
 
 void arch_context_switch(thread_t *oldthread, thread_t *newthread)
 {
-//	dprintf("arch_context_switch: old %p (%s), new %p (%s)\n", oldthread, oldthread->name, newthread, newthread->name);
+//	kprintf("arch_context_switch: old %p (%s), new %p (%s)\n", oldthread, oldthread->name, newthread, newthread->name);
 	arm_context_switch(&oldthread->arch.sp, newthread->arch.sp);
 }
 

arch/x86/faults.c

@@ -20,26 +20,26 @@
  * TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE
  * SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  */
-#include <debug.h>
 #include <arch/x86.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 
 static void dump_fault_frame(struct x86_iframe *frame)
 {
-	dprintf(CRITICAL, " CS:     %04x EIP: %08x EFL: %08x CR2: %08x\n",
+	kprintf(" CS:     %04x EIP: %08x EFL: %08x CR2: %08x\n",
 	        frame->cs, frame->eip, frame->eflags, x86_get_cr2());
-	dprintf(CRITICAL, "EAX: %08x ECX: %08x EDX: %08x EBX: %08x\n",
+	kprintf("EAX: %08x ECX: %08x EDX: %08x EBX: %08x\n",
 	        frame->eax, frame->ecx, frame->edx, frame->ebx);
-	dprintf(CRITICAL, "ESP: %08x EBP: %08x ESI: %08x EDI: %08x\n",
+	kprintf("ESP: %08x EBP: %08x ESI: %08x EDI: %08x\n",
 	        frame->esp, frame->ebp, frame->esi, frame->edi);
-	dprintf(CRITICAL, " DS:     %04x  ES:     %04x  FS:     %04x  GS:     %04x\n",
+	kprintf(" DS:     %04x  ES:     %04x  FS:     %04x  GS:     %04x\n",
 	        frame->ds, frame->es, frame->fs, frame->gs);
 
 	// dump the bottom of the current stack
 	addr_t stack = (addr_t) frame; //(addr_t) (((uint32_t *) frame) + (sizeof(struct x86_iframe) / sizeof(uint32_t) - 1));
 
 	if (stack != 0) {
-		dprintf(CRITICAL, "bottom of stack at 0x%08x:\n", (unsigned int)stack);
+		kprintf("bottom of stack at 0x%08x:\n", (unsigned int)stack);
 		hexdump((void *)stack, 192);
 	}
 }
@@ -47,7 +47,7 @@ static void dump_fault_frame(struct x86_iframe *frame)
 static void exception_die(struct x86_iframe *frame, const char *msg)
 {
 	inc_critical_section();
-	dprintf(CRITICAL, msg);
+	kputs(msg);
 	dump_fault_frame(frame);
 
 	for (;;) {

arch/x86/thread.c

@@ -46,7 +46,7 @@ static void initial_thread_func(void)
 {
 	int ret;
 
-//	dprintf("initial_thread_func: thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
+//	kprintf("initial_thread_func: thread %p calling %p with arg %p\n", current_thread, current_thread->entry, current_thread->arg);
 //	dump_thread(current_thread);
 
 	/* exit the implicit critical section we're within */
@@ -54,7 +54,7 @@ static void initial_thread_func(void)
 
 	ret = current_thread->entry(current_thread->arg);
 
-//	dprintf("initial_thread_func: thread %p exiting with %d\n", current_thread, ret);
+//	kprintf("initial_thread_func: thread %p exiting with %d\n", current_thread, ret);
 
 	thread_exit(ret);
 }
@@ -87,7 +87,7 @@ void arch_thread_initialize(thread_t *t)
 
 void arch_context_switch(thread_t *oldthread, thread_t *newthread)
 {
-	//dprintf(DEBUG, "arch_context_switch: old %p (%s), new %p (%s)\n", oldthread, oldthread->name, newthread, newthread->name);
+	//kprintf("arch_context_switch: old %p (%s), new %p (%s)\n", oldthread, oldthread->name, newthread, newthread->name);
 	
 	__asm__ __volatile__ (
 		"pushl $1f			\n\t"

include/assert.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2008 Travis Geiselbrecht
+ * Copyright (c) 2008-2013 Travis Geiselbrecht
  *
  * Permission is hereby granted, free of charge, to any person obtaining
  * a copy of this software and associated documentation files
@@ -28,13 +28,19 @@
 
 #define ASSERT(x) \
     do { if (unlikely(!(x))) { panic("ASSERT FAILED at (%s:%d): %s\n", __FILE__, __LINE__, #x); } } while (0)
+#define ASSERT_PRINTCALLER(x) \
+    do { if (unlikely(!(x))) { panic("ASSERT FAILED at (%s:%d) caller %p: %s\n", __FILE__, __LINE__, __GET_CALLER(), #x); } } while (0)
 
 #if LK_DEBUGLEVEL > 1
 #define DEBUG_ASSERT(x) \
     do { if (unlikely(!(x))) { panic("DEBUG ASSERT FAILED at (%s:%d): %s\n", __FILE__, __LINE__, #x); } } while (0)
+#define DEBUG_ASSERT_PRINTCALLER(x) \
+    do { if (unlikely(!(x))) { panic("DEBUG ASSERT FAILED at (%s:%d) caller %p: %s\n", __FILE__, __LINE__, __GET_CALLER(), #x); } } while (0)
 #else
 #define DEBUG_ASSERT(x) \
     do { } while(0)
+#define DEBUG_ASSERT_PRINTCALLER(x) \
+    do { } while(0)
 #endif
 
 #define assert(e) DEBUG_ASSERT(e)

include/debug.h

@@ -25,6 +25,7 @@
 
 #include <stdarg.h>
 #include <stddef.h>
+#include <stdio.h>
 #include <compiler.h>
 #include <platform/debug.h>
 
@@ -40,37 +41,15 @@ __BEGIN_CDECLS
 #define INFO 1
 #define SPEW 2
 
-#if !DISABLE_DEBUG_OUTPUT
-
-/* input/output */
-#define _dputc(c) platform_dputc(c)
-int _dputs(const char *str);
-int _dprintf(const char *fmt, ...) __PRINTFLIKE(1, 2);
-int _dvprintf(const char *fmt, va_list ap);
+#define dputc(level, c) do { if ((level) <= LK_DEBUGLEVEL) { putchar(c); } } while (0)
+#define dputs(level, str) do { if ((level) <= LK_DEBUGLEVEL) { fputs(str, stdout); } } while (0)
+#define dprintf(level, x...) do { if ((level) <= LK_DEBUGLEVEL) { printf(x); } } while (0)
+#define dvprintf(level, x...) do { if ((level) <= LK_DEBUGLEVEL) { vprintf(x); } } while (0)
 
 /* dump memory */
 void hexdump(const void *ptr, size_t len);
 void hexdump8(const void *ptr, size_t len);
 
-#else
-
-/* input/output */
-static inline void _dputc(char c) { }
-static inline int _dputs(const char *str) { return 0; }
-static inline int __PRINTFLIKE(1, 2) _dprintf(const char *fmt, ...) { return 0; }
-static inline int _dvprintf(const char *fmt, va_list ap) { return 0; }
-
-/* dump memory */
-static inline void hexdump(const void *ptr, size_t len) { }
-static inline void hexdump8(const void *ptr, size_t len) { }
-
-#endif /* DISABLE_DEBUG_OUTPUT */
-
-#define dputc(level, str) do { if ((level) <= LK_DEBUGLEVEL) { _dputc(str); } } while (0)
-#define dputs(level, str) do { if ((level) <= LK_DEBUGLEVEL) { _dputs(str); } } while (0)
-#define dprintf(level, x...) do { if ((level) <= LK_DEBUGLEVEL) { _dprintf(x); } } while (0)
-#define dvprintf(level, x...) do { if ((level) <= LK_DEBUGLEVEL) { _dvprintf(x); } } while (0)
-
 /* systemwide halts */
 void halt(void) __NO_RETURN;
 

include/kernel/debug.h

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2012 Travis Geiselbrecht
+ * Copyright (c) 2012-2013 Travis Geiselbrecht
  *
  * Permission is hereby granted, free of charge, to any person obtaining
  * a copy of this software and associated documentation files
@@ -24,6 +24,8 @@
 #define __KERNEL_DEBUG_H
 
 #include <debug.h>
+#include <compiler.h>
+#include <stdarg.h>
 
 /* kernel event log */
 #if WITH_KERNEL_EVLOG
@@ -63,5 +65,23 @@ enum {
 #define KEVLOG_IRQ_ENTER(irqn) kernel_evlog_add(KERNEL_EVLOG_IRQ_ENTER, (uintptr_t)irqn, 0)
 #define KEVLOG_IRQ_EXIT(irqn) kernel_evlog_add(KERNEL_EVLOG_IRQ_EXIT, (uintptr_t)irqn, 0)
 
+/*
+ * kprintf and friends
+ *
+ * Is defined to always go directly to the current platform debug mechanism.
+ * Safe to be called in any context.
+ */
+#if !DISABLE_DEBUG_OUTPUT
+void kputc(char c);
+void kputs(const char *str);
+int kprintf(const char *fmt, ...) __PRINTFLIKE(1, 2);
+int kvprintf(const char *fmt, va_list ap);
+#else
+static inline void kputc(char c) { }
+static inline void kputs(const char *str) { return 0; }
+static inline int __PRINTFLIKE(1, 2) kprintf(const char *fmt, ...) { return 0; }
+static inline int kvprintf(const char *fmt, va_list ap) { return 0; }
+#endif
+
 #endif
 

include/stdio.h

@@ -26,15 +26,17 @@
 #include <compiler.h>
 #include <debug.h>
 #include <printf.h>
+#include <sys/types.h>
 
 __BEGIN_CDECLS
 
+#define __FILE_READ_NONBLOCK  (0x1)
+
 typedef struct FILE {
 	void *ctx;
-	int (*fputc)(void *ctx, int c);
-	int (*fputs)(void *ctx, const char *s);
-	int (*fgetc)(void *ctx);
-	int (*vfprintf)(void *ctx, const char *fmt, va_list ap);
+
+	ssize_t (*write)(void *ctx, const void *ptr, size_t len);
+	ssize_t (*read)(void *ctx, void *ptr, size_t len, unsigned int flags);
 } FILE;
 
 extern FILE __stdio_FILEs[];

include/trace.h

@@ -39,4 +39,17 @@
 #define LTRACE do { if (LOCAL_TRACE) { TRACE; } } while (0)
 #define LTRACEF(x...) do { if (LOCAL_TRACE) { TRACEF(x); } } while (0)
 
+/* kernel versions of the above */
+#define KTRACE_ENTRY kprintf("%s: entry\n", __PRETTY_FUNCTION__)
+#define KTRACE_EXIT kprintf("%s: exit\n", __PRETTY_FUNCTION__)
+#define KTRACE_ENTRY_OBJ kprintf("%s: entry obj %p\n", __PRETTY_FUNCTION__, this)
+#define KTRACE_EXIT_OBJ kprintf("%s: exit obj %p\n", __PRETTY_FUNCTION__, this)
+#define KTRACE kprintf("%s:%d\n", __PRETTY_FUNCTION__, __LINE__)
+#define KTRACEF(str, x...) do { kprintf("%s:%d: " str, __PRETTY_FUNCTION__, __LINE__, ## x); } while (0)
+
+#define KLTRACE_ENTRY do { if (LOCAL_TRACE) { LTRACE_ENTRY; } } while (0)
+#define KLTRACE_EXIT do { if (LOCAL_TRACE) { LTRACE_EXIT; } } while (0)
+#define KLTRACE do { if (LOCAL_TRACE) { LTRACE; } } while (0)
+#define KLTRACEF(x...) do { if (LOCAL_TRACE) { LTRACEF(x); } } while (0)
+
 #endif

kernel/debug.c

@@ -31,13 +31,13 @@
  * @brief  Debug console functions.
  */
 
+#include <kernel/debug.h>
 #include <debug.h>
 #include <stdio.h>
-#include <kernel/thread.h>
-#include <kernel/timer.h>
-#include <kernel/debug.h>
 #include <err.h>
 #include <platform.h>
+#include <kernel/thread.h>
+#include <kernel/timer.h>
 
 #if WITH_LIB_CONSOLE
 #include <lib/console.h>
@@ -101,8 +101,8 @@ static enum handler_return threadload(struct timer *t, lk_time_t now, void *arg)
 
 	uint busypercent = (busy_time * 10000) / (1000000);
 
-//	printf("idle_time %lld, busytime %lld\n", idle_time - last_idle_time, busy_time);
-	printf("LOAD: %d.%02d%%, cs %d, ints %d, timer ints %d, timers %d\n", busypercent / 100, busypercent % 100,
+//	kprintf("idle_time %lld, busytime %lld\n", idle_time - last_idle_time, busy_time);
+	kprintf("LOAD: %d.%02d%%, cs %d, ints %d, timer ints %d, timers %d\n", busypercent / 100, busypercent % 100,
 	       thread_stats.context_switches - old_stats.context_switches,
 	       thread_stats.interrupts - old_stats.interrupts,
 	       thread_stats.timer_ints - old_stats.timer_ints,
@@ -208,4 +208,50 @@ static int cmd_kevlog(int argc, const cmd_args *argv)
 
 #endif // WITH_KERNEL_EVLOG
 
+#if !DISABLE_DEBUG_OUTPUT
+
+/* kprintf and friends */
+void kputc(char c)
+{
+	platform_dputc(c);
+}
+
+void kputs(const char *str)
+{
+	for (; *str; str++) {
+		platform_dputc(*str);
+	}
+}
+
+static int kprintf_output_func(char c, void *state)
+{
+	platform_dputc(c);
+
+	return INT_MAX;
+}
+
+int kprintf(const char *fmt, ...)
+{
+	int err;
+
+	va_list ap;
+	va_start(ap, fmt);
+	err = _printf_engine(&kprintf_output_func, NULL, fmt, ap);
+	va_end(ap);
+
+	return err;
+}
+
+int kvprintf(const char *fmt, va_list ap)
+{
+	int err;
+
+	err = _printf_engine(&kprintf_output_func, NULL, fmt, ap);
+
+	return err;
+}
+
+#endif // !DISABLE_DEBUG_OUTPUT
+
+/* vim: set ts=4 sw=4 noexpandtab: */
 

kernel/init.c

@@ -32,11 +32,9 @@ void kernel_init(void)
 	kernel_evlog_init();
 
 	// initialize the threading system
-	dprintf(SPEW, "initializing threads\n");
 	thread_init();
 
 	// initialize kernel timers
-	dprintf(SPEW, "initializing timers\n");
 	timer_init();
 }
 

kernel/thread.c

@@ -328,7 +328,7 @@ void thread_exit(int retcode)
 	ASSERT(current_thread->state == THREAD_RUNNING);
 #endif
 
-//	dprintf("thread_exit: current %p\n", current_thread);
+//	kprintf("thread_exit: current %p\n", current_thread);
 
 	enter_critical_section();
 
@@ -382,9 +382,6 @@ void thread_resched(void)
 	thread_t *oldthread;
 	thread_t *newthread;
 
-//	printf("thread_resched: current %p: ", current_thread);
-//	dump_thread(current_thread);
-
 #if THREAD_CHECKS
 	ASSERT(in_critical_section());
 #endif
@@ -402,7 +399,6 @@ void thread_resched(void)
 #endif
 
 	int next_queue = HIGHEST_PRIORITY - __builtin_clz(run_queue_bitmap) - (32 - NUM_PRIORITIES);
-	//dprintf(SPEW, "bitmap 0x%x, next %d\n", run_queue_bitmap, next_queue);
 
 	newthread = list_remove_head_type(&run_queue[next_queue], thread_t, queue_node);
 
@@ -413,9 +409,6 @@ void thread_resched(void)
 	ASSERT(newthread);
 #endif
 
-//	printf("newthread: ");
-//	dump_thread(newthread);
-
 	newthread->state = THREAD_RUNNING;
 
 	if (newthread == oldthread)
@@ -720,19 +713,19 @@ static const char *thread_state_to_str(enum thread_state state)
  */
 void dump_thread(thread_t *t)
 {
-	dprintf(INFO, "dump_thread: t %p (%s)\n", t, t->name);
-	dprintf(INFO, "\tstate %s, priority %d, remaining quantum %d, critical section %d\n",
+	kprintf("dump_thread: t %p (%s)\n", t, t->name);
+	kprintf("\tstate %s, priority %d, remaining quantum %d, critical section %d\n",
 				  thread_state_to_str(t->state), t->priority, t->remaining_quantum,
 				  t->saved_critical_section_count);
-	dprintf(INFO, "\tstack %p, stack_size %zd\n", t->stack, t->stack_size);
-	dprintf(INFO, "\tentry %p, arg %p, flags 0x%x\n", t->entry, t->arg, t->flags);
-	dprintf(INFO, "\twait queue %p, wait queue ret %d\n", t->blocking_wait_queue, t->wait_queue_block_ret);
-	dprintf(INFO, "\ttls:");
+	kprintf("\tstack %p, stack_size %zd\n", t->stack, t->stack_size);
+	kprintf("\tentry %p, arg %p, flags 0x%x\n", t->entry, t->arg, t->flags);
+	kprintf("\twait queue %p, wait queue ret %d\n", t->blocking_wait_queue, t->wait_queue_block_ret);
+	kprintf("\ttls:");
 	int i;
 	for (i=0; i < MAX_TLS_ENTRY; i++) {
-		dprintf(INFO, " 0x%x", t->tls[i]);
+		kprintf(" 0x%x", t->tls[i]);
 	}
-	dprintf(INFO, "\n");
+	kprintf("\n");
 }
 
 /**

kernel/timer.c

@@ -62,7 +62,7 @@ static void insert_timer_in_queue(timer_t *timer)
 {
 	timer_t *entry;
 
-	LTRACEF("timer %p, scheduled %lu, periodic %lu\n", timer, timer->scheduled_time, timer->periodic_time);
+	KLTRACEF("timer %p, scheduled %lu, periodic %lu\n", timer, timer->scheduled_time, timer->periodic_time);
 
 	list_for_every_entry(&timer_queue, entry, timer_t, node) {
 		if (TIME_GT(entry->scheduled_time, timer->scheduled_time)) {
@@ -79,7 +79,7 @@ static void timer_set(timer_t *timer, lk_time_t delay, lk_time_t period, timer_c
 {
 	lk_time_t now;
 
-	LTRACEF("timer %p, delay %lu, period %lu, callback %p, arg %p, now %lu\n", timer, delay, period, callback, arg, now);
+	KLTRACEF("timer %p, delay %lu, period %lu, callback %p, arg %p, now %lu\n", timer, delay, period, callback, arg, now);
 
 	DEBUG_ASSERT(timer->magic == TIMER_MAGIC);
 
@@ -93,7 +93,7 @@ static void timer_set(timer_t *timer, lk_time_t delay, lk_time_t period, timer_c
 	timer->callback = callback;
 	timer->arg = arg;
 
-	LTRACEF("scheduled time %lu\n", timer->scheduled_time);
+	KLTRACEF("scheduled time %lu\n", timer->scheduled_time);
 
 	enter_critical_section();
 
@@ -102,7 +102,7 @@ static void timer_set(timer_t *timer, lk_time_t delay, lk_time_t period, timer_c
 #if PLATFORM_HAS_DYNAMIC_TIMER
 	if (list_peek_head_type(&timer_queue, timer_t, node) == timer) {
 		/* we just modified the head of the timer queue */
-		LTRACEF("setting new timer for %u msecs\n", (uint)delay);
+		KLTRACEF("setting new timer for %u msecs\n", (uint)delay);
 		platform_set_oneshot_timer(timer_tick, NULL, delay);
 	}
 #endif
@@ -179,7 +179,7 @@ void timer_cancel(timer_t *timer)
 	/* see if we've just modified the head of the timer queue */
 	timer_t *newhead = list_peek_head_type(&timer_queue, timer_t, node);
 	if (newhead == NULL) {
-		LTRACEF("clearing old hw timer, nothing in the queue\n");
+		KLTRACEF("clearing old hw timer, nothing in the queue\n");
 		platform_stop_timer();
 	} else if (newhead != oldhead) {
 		lk_time_t delay;
@@ -190,7 +190,7 @@ void timer_cancel(timer_t *timer)
 		else
 			delay = newhead->scheduled_time - now;
 
-		LTRACEF("setting new timer to %u\n", (uint) delay);
+		KLTRACEF("setting new timer to %u\n", (uint) delay);
 		platform_set_oneshot_timer(timer_tick, NULL, delay);
 	}
 #endif
@@ -207,29 +207,29 @@ static enum handler_return timer_tick(void *arg, lk_time_t now)
 	THREAD_STATS_INC(timer_ints);
 //	KEVLOG_TIMER_TICK(); // enable only if necessary
 
-	LTRACEF("now %lu, sp %p\n", now, __GET_FRAME());
+	KLTRACEF("now %lu, sp %p\n", now, __GET_FRAME());
 
 	for (;;) {
 		/* see if there's an event to process */
 		timer = list_peek_head_type(&timer_queue, timer_t, node);
 		if (likely(timer == 0))
 			break;
-		LTRACEF("next item on timer queue %p at %lu now %lu (%p, arg %p)\n", timer, timer->scheduled_time, now, timer->callback, timer->arg);
+		KLTRACEF("next item on timer queue %p at %lu now %lu (%p, arg %p)\n", timer, timer->scheduled_time, now, timer->callback, timer->arg);
 		if (likely(TIME_LT(now, timer->scheduled_time)))
 			break;
 
 		/* process it */
-		LTRACEF("timer %p\n", timer);
+		KLTRACEF("timer %p\n", timer);
 		DEBUG_ASSERT(timer && timer->magic == TIMER_MAGIC);
 		list_delete(&timer->node);
 
-		LTRACEF("dequeued timer %p, scheduled %lu periodic %lu\n", timer, timer->scheduled_time, timer->periodic_time);
+		KLTRACEF("dequeued timer %p, scheduled %lu periodic %lu\n", timer, timer->scheduled_time, timer->periodic_time);
 
 		THREAD_STATS_INC(timers);
 
 		bool periodic = timer->periodic_time > 0;
 
-		LTRACEF("timer %p firing callback %p, arg %p\n", timer, timer->callback, timer->arg);
+		KLTRACEF("timer %p firing callback %p, arg %p\n", timer, timer->callback, timer->arg);
 		KEVLOG_TIMER_CALL(timer->callback, timer->arg);
 		if (timer->callback(timer, now, timer->arg) == INT_RESCHEDULE)
 			ret = INT_RESCHEDULE;
@@ -238,7 +238,7 @@ static enum handler_return timer_tick(void *arg, lk_time_t now)
 		 * by the callback put it back in the list
 		 */
 		if (periodic && !list_in_list(&timer->node) && timer->periodic_time > 0) {
-			LTRACEF("periodic timer, period %u\n", (uint)timer->periodic_time);
+			KLTRACEF("periodic timer, period %u\n", (uint)timer->periodic_time);
 			timer->scheduled_time = now + timer->periodic_time;
 			insert_timer_in_queue(timer);
 		}
@@ -253,7 +253,7 @@ static enum handler_return timer_tick(void *arg, lk_time_t now)
 
 		lk_time_t delay = timer->scheduled_time - now;
 
-		LTRACEF("setting new timer for %u msecs for event %p\n", (uint)delay, timer);
+		KLTRACEF("setting new timer for %u msecs for event %p\n", (uint)delay, timer);
 		platform_set_oneshot_timer(timer_tick, NULL, delay);
 	}
 #else

lib/debug/debug.c

@@ -21,8 +21,8 @@
  * SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  */
 
-#include <ctype.h>
 #include <debug.h>
+#include <ctype.h>
 #include <stdlib.h>
 #include <printf.h>
 #include <stdio.h>
@@ -31,6 +31,7 @@
 #include <arch/ops.h>
 #include <platform.h>
 #include <platform/debug.h>
+#include <kernel/debug.h>
 #include <kernel/thread.h>
 
 void spin(uint32_t usecs)
@@ -49,98 +50,16 @@ void halt(void)
 
 void _panic(void *caller, const char *fmt, ...)
 {
-	dprintf(ALWAYS, "panic (caller %p): ", caller);
+	kprintf("panic (caller %p): ", caller);
 
 	va_list ap;
 	va_start(ap, fmt);
-	_dvprintf(fmt, ap);
+	kvprintf(fmt, ap);
 	va_end(ap);
 
 	halt();
 }
 
-static int __debug_stdio_fputc(void *ctx, int c)
-{
-	_dputc(c);
-	return 0;
-}
-
-static int __debug_stdio_fputs(void *ctx, const char *s)
-{
-	return _dputs(s);
-}
-
-static int __debug_stdio_fgetc(void *ctx)
-{
-	char c;
-	int err;
-
-	err = platform_dgetc(&c, true);
-	if (err < 0)
-		return err;
-	return (unsigned char)c;
-}
-
-static int __debug_stdio_vfprintf(void *ctx, const char *fmt, va_list ap)
-{
-	return _dvprintf(fmt, ap);
-}
-
-#define DEFINE_STDIO_DESC(id)						\
-	[(id)]	= {							\
-		.ctx		= &__stdio_FILEs[(id)],			\
-		.fputc		= __debug_stdio_fputc,			\
-		.fputs		= __debug_stdio_fputs,			\
-		.fgetc		= __debug_stdio_fgetc,			\
-		.vfprintf	= __debug_stdio_vfprintf,		\
-	}
-
-FILE __stdio_FILEs[3] = {
-	DEFINE_STDIO_DESC(0), /* stdin */
-	DEFINE_STDIO_DESC(1), /* stdout */
-	DEFINE_STDIO_DESC(2), /* stderr */
-};
-#undef DEFINE_STDIO_DESC
-
-#if !DISABLE_DEBUG_OUTPUT
-
-int _dputs(const char *str)
-{
-	while (*str != 0) {
-		_dputc(*str++);
-	}
-
-	return 0;
-}
-
-static int _dprintf_output_func(char c, void *state)
-{
-	_dputc(c);
-
-	return INT_MAX;
-}
-
-int _dprintf(const char *fmt, ...)
-{
-	int err;
-
-	va_list ap;
-	va_start(ap, fmt);
-	err = _printf_engine(&_dprintf_output_func, NULL, fmt, ap);
-	va_end(ap);
-
-	return err;
-}
-
-int _dvprintf(const char *fmt, va_list ap)
-{
-	int err;
-
-	err = _printf_engine(&_dprintf_output_func, NULL, fmt, ap);
-
-	return err;
-}
-
 void hexdump(const void *ptr, size_t len)
 {
 	addr_t address = (addr_t)ptr;
@@ -179,5 +98,4 @@ void hexdump8(const void *ptr, size_t len)
 	}
 }
 
-#endif // !DISABLE_DEBUG_OUTPUT
-
+/* vim: set ts=4 sw=4 noexpandtab: */

lib/libc/stdio.c

@@ -20,24 +20,37 @@
  * TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE
  * SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
  */
-#include <debug.h>
 #include <stdio.h>
+#include <debug.h>
 #include <stdarg.h>
+#include <string.h>
+#include <assert.h>
+#include <err.h>
 #include <sys/types.h>
 #include <platform/debug.h>
+#include <kernel/thread.h>
 
 int fputc(int c, FILE *fp)
 {
-	return fp->fputc(fp->ctx, c);
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
+	if (!fp->write)
+		return 0;
+
+	return fp->write(fp->ctx, &c, 1);
 }
 
 int putchar(int c)
 {
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
 	return fputc(c, stdout);
 }
 
 int puts(const char *str)
 {
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
 	int err = fputs(str, stdout);
 	if (err >= 0)
 		err = fputc('\n', stdout);
@@ -46,22 +59,55 @@ int puts(const char *str)
 
 int fputs(const char *s, FILE *fp)
 {
-	return fp->fputs(fp->ctx, s);
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
+	if (!fp->write)
+		return 0;
+
+	size_t len = strlen(s);
+
+	return fp->write(fp->ctx, s, len);
 }
 
 int getc(FILE *fp)
 {
-	return fp->fgetc(fp->ctx);
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
+	unsigned char c;
+
+	if (!fp->read)
+		return 0;
+
+	ssize_t len = fp->read(fp->ctx, &c, 1, 0);
+	if (len == 1)
+		return c;
+	else if (len == 0)
+		return ERR_IO;
+	else
+		return len;
 }
 
 int getchar(void)
 {
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
 	return getc(stdin);
 }
 
+static int _FILE_printf_output_routine(char c, void *state)
+{
+	FILE *fp = (FILE *)state;
+
+	fputc(c, fp);
+
+	return INT_MAX;
+}
+
 int vfprintf(FILE *fp, const char *fmt, va_list ap)
 {
-	return fp->vfprintf(fp->ctx, fmt, ap);
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
+	return _printf_engine(&_FILE_printf_output_routine, (void *)fp, fmt, ap);
 }
 
 int fprintf(FILE *fp, const char *fmt, ...)
@@ -69,6 +115,8 @@ int fprintf(FILE *fp, const char *fmt, ...)
 	va_list ap;
 	int err;
 
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
 	va_start(ap, fmt);
 	err = vfprintf(fp, fmt, ap);
 	va_end(ap);
@@ -80,9 +128,49 @@ int _printf(const char *fmt, ...)
 	va_list ap;
 	int err;
 
+	DEBUG_ASSERT_PRINTCALLER(!in_critical_section());
+
 	va_start(ap, fmt);
 	err = vfprintf(stdout, fmt, ap);
 	va_end(ap);
 
 	return err;
 }
+
+/* default stdio output target */
+ssize_t __debug_stdio_write(void *ctx, const void *_ptr, size_t len)
+{
+	const char *ptr = _ptr;
+
+	for (size_t i = 0; i < len; i++)
+		platform_dputc(ptr[i]);
+
+	return len;
+}
+
+ssize_t __debug_stdio_read(void *ctx, void *ptr, size_t len, unsigned int flags)
+{
+	int err;
+
+	err = platform_dgetc(ptr, (flags & __FILE_READ_NONBLOCK) ? false : true);
+	if (err < 0)
+		return err;
+
+	return 1;
+}
+
+#define DEFINE_STDIO_DESC(id)						\
+	[(id)]	= {							\
+		.ctx		= &__stdio_FILEs[(id)],			\
+		.write		= __debug_stdio_write,			\
+		.read		= __debug_stdio_read,			\
+	}
+
+FILE __stdio_FILEs[3] = {
+	DEFINE_STDIO_DESC(0), /* stdin */
+	DEFINE_STDIO_DESC(1), /* stdout */
+	DEFINE_STDIO_DESC(2), /* stderr */
+};
+#undef DEFINE_STDIO_DESC
+
+/* vim: set ts=4 sw=4 noexpandtab: */

platform/sam3/debug.c

@@ -82,7 +82,7 @@ void sam_debug_init(void)
 void platform_dputc(char c)
 {
 	if (c == '\n') {
-		_dputc('\r');
+		platform_dputc('\r');
 	}
 
 	while (!uart_is_tx_ready(UART))

platform/stellaris/debug.c

@@ -26,9 +26,10 @@
 #include <stdio.h>
 #include <lib/cbuf.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 #include <platform/debug.h>
-#include <arch/ops.h>
 #include <target/debugconfig.h>
+#include <arch/ops.h>
 #include <arch/arm/cm.h>
 
 #include "ti_driverlib.h"
@@ -98,13 +99,12 @@ void stellaris_debug_init(void)
 	UARTIntEnable(DEBUG_UART, UART_INT_RX | UART_INT_RT);
 
 	NVIC_EnableIRQ(INT_UART0 - 16);
-
 }
 
 void platform_dputc(char c)
 {
 	if (c == '\n') {
-		_dputc('\r');
+		UARTCharPut(DEBUG_UART, '\r');
 	}
 
 	UARTCharPut(DEBUG_UART, c);
@@ -117,7 +117,7 @@ int platform_dgetc(char *c, bool wait)
 
 void platform_halt(void)
 {
-	dprintf(ALWAYS, "HALT: spinning forever...\n");
+	kprintf("HALT: spinning forever...\n");
 	for (;;);
 }
 

top/init.c

@@ -31,6 +31,7 @@
 #include <compiler.h>
 #include <debug.h>
 #include <trace.h>
+#include <kernel/debug.h>
 
 #define LOCAL_TRACE 0
 #define TRACE_INIT 0
@@ -42,18 +43,18 @@ static uint last_init_level = 0;
 
 int lk_init_level(uint level)
 {
-    LTRACEF("level %#x, last_init_level %#x\n", level, last_init_level);
+    KLTRACEF("level %#x, last_init_level %#x\n", level, last_init_level);
 
     uint last_called_level = last_init_level;
     const struct lk_init_struct *last = NULL;
     for (;;) {
         /* search for the lowest uncalled hook to call */
-        LTRACEF("last %p, last_called_level %#x\n", last, last_called_level);
+        KLTRACEF("last %p, last_called_level %#x\n", last, last_called_level);
 
         const struct lk_init_struct *found = NULL;
         bool seen_last = false;
         for (const struct lk_init_struct *ptr = __lk_init; ptr != __lk_init_end; ptr++) {
-            LTRACEF("looking at %p (%s) level %#x, seen_last %d\n", ptr, ptr->name, ptr->level, seen_last);
+            KLTRACEF("looking at %p (%s) level %#x, seen_last %d\n", ptr, ptr->name, ptr->level, seen_last);
 
             if (ptr == last)
                 seen_last = true;
@@ -86,7 +87,7 @@ int lk_init_level(uint level)
             break;
 
 #if TRACE_INIT
-        printf("INIT: calling hook %p (%s) at level %#x\n", found->hook, found->name, found->level);
+        kprintf("INIT: calling hook %p (%s) at level %#x\n", found->hook, found->name, found->level);
 #endif
         found->hook(found->level);
         last_called_level = found->level;

top/main.c

@@ -34,6 +34,7 @@
 #include <target.h>
 #include <lib/heap.h>
 #include <kernel/thread.h>
+#include <kernel/debug.h>
 #include <lk/init.h>
 
 extern void *__ctor_list;
@@ -81,14 +82,13 @@ void lk_main(void)
 	lk_init_level(LK_INIT_LEVEL_TARGET_EARLY - 1);
 	target_early_init();
 
-	dprintf(INFO, "welcome to lk\n\n");
+	kprintf("\nWelcome to LK\n");
+	kprintf("Source available at https://github.com/travisg/lk or git://git.newos.org/lk.git\n");
 
 	// deal with any static constructors
-	dprintf(SPEW, "calling constructors\n");
 	call_constructors();
 
 	// bring up the kernel heap
-	dprintf(SPEW, "initializing heap\n");
 	lk_init_level(LK_INIT_LEVEL_HEAP - 1);
 	heap_init();
 
@@ -99,7 +99,6 @@ void lk_main(void)
 	lk_init_level(LK_INIT_LEVEL_THREADING - 1);
 
 	// create a thread to complete system initialization
-	dprintf(SPEW, "creating bootstrap completion thread\n");
 	thread_t *t = thread_create("bootstrap2", &bootstrap2, NULL, DEFAULT_PRIORITY, DEFAULT_STACK_SIZE);
 	thread_detach(t);
 	thread_resume(t);
@@ -110,22 +109,17 @@ void lk_main(void)
 
 static int bootstrap2(void *arg)
 {
-	dprintf(SPEW, "top of bootstrap2()\n");
-
 	lk_init_level(LK_INIT_LEVEL_ARCH - 1);
 	arch_init();
 
 	// initialize the rest of the platform
-	dprintf(SPEW, "initializing platform\n");
 	lk_init_level(LK_INIT_LEVEL_PLATFORM - 1);
 	platform_init();
 
 	// initialize the target
-	dprintf(SPEW, "initializing target\n");
 	lk_init_level(LK_INIT_LEVEL_TARGET - 1);
 	target_init();
 
-	dprintf(SPEW, "calling apps_init()\n");
 	lk_init_level(LK_INIT_LEVEL_APPS - 1);
 	apps_init();