From 5bf48697e4f53509dec31ef5b2474f8744bd8712 Mon Sep 17 00:00:00 2001 From: Aggelos Economopoulos Date: Fri, 30 Dec 2011 05:38:34 -0800 Subject: [PATCH] Modify ktr(4) to be typesafe - Use a struct copy to place the logged values directly into the destination buffer without forcing a memcpy. - This also fixes event logging on x86_64, as we no longer rely on the i386 calling convention for functions with a variable number of arguments. - Verify that the arguments match the specified format. - Update callsites. Note that this requires userspace changes! ktrdump(8) needs to be adjusted even on i386 (%c and %hd are no longer promoted as per the C rules). We need very special handling on x86_64 too. --- sys/bus/usb/usb_mem.c | 24 +++--- sys/dev/disk/dm/targets/crypt/dm_target_crypt.c | 18 ++-- sys/dev/netif/bge/if_bge.c | 6 +- sys/dev/netif/em/if_em.c | 10 +- sys/dev/netif/emx/if_emx.c | 10 +- sys/kern/dsched/bfq/bfq_ktr.h | 9 ++- sys/kern/kern_ktr.c | 63 ++++++--------- sys/kern/kern_poll.c | 4 +- sys/kern/kern_slaballoc.c | 37 ++++----- sys/kern/kern_synch.c | 10 +- sys/kern/lwkt_ipiq.c | 24 +++--- sys/kern/lwkt_serialize.c | 26 +++--- sys/kern/lwkt_thread.c | 13 +-- sys/kern/lwkt_token.c | 23 +++--- sys/net/if.c | 18 ++-- sys/net/if_ethersubr.c | 10 +- sys/platform/pc32/i386/trap.c | 21 +++--- sys/platform/pc64/x86_64/trap.c | 21 +++--- sys/sys/ktr.h | 97 ++++++++++++++++------ 19 files changed, 239 insertions(+), 205 deletions(-) diff --git a/sys/bus/usb/usb_mem.c b/sys/bus/usb/usb_mem.c index 8e3b4c4..ee42e4e 100644 --- a/sys/bus/usb/usb_mem.c +++ b/sys/bus/usb/usb_mem.c @@ -68,23 +68,23 @@ #include /* just for usb_dma_t */ #include -#define USBKTR_STRING "ptr=%p bus=%p size=%d align=%d" -#define USBKTR_ARG_SIZE (sizeof(void *) * 2 + sizeof(int) * 2) +#define USBKTR_STRING "ptr=%p bus=%p size=%zu align=%zu" +#define USBKTR_ARGS void *p, usbd_bus_handle bus, size_t size, size_t align #if !defined(KTR_USB_MEMORY) #define KTR_USB_MEMORY KTR_ALL #endif KTR_INFO_MASTER(usbmem); -KTR_INFO(KTR_USB_MEMORY, usbmem, alloc_full, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, alloc_frag, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, free_full, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, free_frag, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, blkalloc, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, blkalloc2, 0, USBKTR_STRING, USBKTR_ARG_SIZE); -KTR_INFO(KTR_USB_MEMORY, usbmem, blkfree, 0, USBKTR_STRING, USBKTR_ARG_SIZE); +KTR_INFO(KTR_USB_MEMORY, usbmem, alloc_full, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, alloc_frag, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, free_full, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, free_frag, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, blkalloc, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, blkalloc2, 0, USBKTR_STRING, USBKTR_ARGS); +KTR_INFO(KTR_USB_MEMORY, usbmem, blkfree, 0, USBKTR_STRING, USBKTR_ARGS); #define logmemory(name, ptr, bus, size, align) \ - KTR_LOG(usbmem_ ## name, ptr, bus, (int)size, (int)align); + KTR_LOG(usbmem_ ## name, ptr, bus, size, align); #ifdef USB_DEBUG #define DPRINTF(x) if (usbdebug) kprintf x @@ -283,10 +283,10 @@ usb_freemem(usbd_bus_handle bus, usb_dma_t *p) if (p->block->fullblock) { DPRINTFN(1, ("usb_freemem: large free\n")); usb_block_freemem(p->block); - logmemory(free_full, p, bus, 0, 0); + logmemory(free_full, p, bus, (size_t)0, (size_t)0); return; } - logmemory(free_frag, p, bus, 0, 0); + logmemory(free_frag, p, bus, (size_t)0, (size_t)0); f = KERNADDR(p, 0); f->block = p->block; f->offs = p->offs; diff --git a/sys/dev/disk/dm/targets/crypt/dm_target_crypt.c b/sys/dev/disk/dm/targets/crypt/dm_target_crypt.c index aa489ea..d583c93 100644 --- a/sys/dev/disk/dm/targets/crypt/dm_target_crypt.c +++ b/sys/dev/disk/dm/targets/crypt/dm_target_crypt.c @@ -66,27 +66,27 @@ KTR_INFO_MASTER(dmcrypt); #endif KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_dispatch, 0, - "crypto_dispatch(%p)", sizeof(void *)); + "crypto_dispatch(%p)", struct cryptop *crp); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypt_strategy, 0, - "crypt_strategy(b_cmd = %d, bp = %p)", sizeof(int) + sizeof(void *)); + "crypt_strategy(b_cmd = %d, bp = %p)", int cmd, struct buf *bp); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_write_start, 1, "crypto_write_start(crp = %p, bp = %p, sector = %d/%d)", - sizeof(void *) + sizeof(void *) + sizeof(int) + sizeof(int)); + struct cryptop *crp, struct buf *bp, int i, int sectors); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_cb_write_done, 1, "crypto_cb_write_done(crp = %p, bp = %p, n = %d)", - sizeof(void *) + sizeof(void *) + sizeof(int)); + struct cryptop *crp, struct buf *bp, int n); KTR_INFO(KTR_DMCRYPT, dmcrypt, bio_write_done, 1, - "bio_write_done(bp = %p)", sizeof(void *)); + "bio_write_done(bp = %p)", struct buf *bp); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_write_retry, 1, - "crypto_write_retry(crp = %p)", sizeof(void *)); + "crypto_write_retry(crp = %p)", struct buf *bp); KTR_INFO(KTR_DMCRYPT, dmcrypt, bio_read_done, 2, - "bio_read_done(bp = %p)", sizeof(void *)); + "bio_read_done(bp = %p)", struct buf *bp); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_read_start, 2, "crypto_read_start(crp = %p, bp = %p, sector = %d/%d)", - sizeof(void *) + sizeof(void *) + sizeof(int) + sizeof(int)); + struct cryptop *crp, struct buf *bp, int i, int sectors); KTR_INFO(KTR_DMCRYPT, dmcrypt, crypto_cb_read_done, 2, "crypto_cb_read_done(crp = %p, bp = %p, n = %d)", - sizeof(void *) + sizeof(void *) + sizeof(int)); + struct cryptop *crp, struct buf *bp, int n); struct target_crypt_config; diff --git a/sys/dev/netif/bge/if_bge.c b/sys/dev/netif/bge/if_bge.c index e1a65d4..4a2154b 100644 --- a/sys/dev/netif/bge/if_bge.c +++ b/sys/dev/netif/bge/if_bge.c @@ -396,9 +396,9 @@ TUNABLE_INT("hw.bge.tx_max_coal_bds", &bge_tx_max_coal_bds); #define KTR_IF_BGE KTR_ALL #endif KTR_INFO_MASTER(if_bge); -KTR_INFO(KTR_IF_BGE, if_bge, intr, 0, "intr", 0); -KTR_INFO(KTR_IF_BGE, if_bge, rx_pkt, 1, "rx_pkt", 0); -KTR_INFO(KTR_IF_BGE, if_bge, tx_pkt, 2, "tx_pkt", 0); +KTR_INFO(KTR_IF_BGE, if_bge, intr, 0, "intr"); +KTR_INFO(KTR_IF_BGE, if_bge, rx_pkt, 1, "rx_pkt"); +KTR_INFO(KTR_IF_BGE, if_bge, tx_pkt, 2, "tx_pkt"); #define logif(name) KTR_LOG(if_bge_ ## name) static device_method_t bge_methods[] = { diff --git a/sys/dev/netif/em/if_em.c b/sys/dev/netif/em/if_em.c index 73f81e6..7aa5d56 100644 --- a/sys/dev/netif/em/if_em.c +++ b/sys/dev/netif/em/if_em.c @@ -396,11 +396,11 @@ static int em_display_debug_stats = 0; #define KTR_IF_EM KTR_ALL #endif KTR_INFO_MASTER(if_em); -KTR_INFO(KTR_IF_EM, if_em, intr_beg, 0, "intr begin", 0); -KTR_INFO(KTR_IF_EM, if_em, intr_end, 1, "intr end", 0); -KTR_INFO(KTR_IF_EM, if_em, pkt_receive, 4, "rx packet", 0); -KTR_INFO(KTR_IF_EM, if_em, pkt_txqueue, 5, "tx packet", 0); -KTR_INFO(KTR_IF_EM, if_em, pkt_txclean, 6, "tx clean", 0); +KTR_INFO(KTR_IF_EM, if_em, intr_beg, 0, "intr begin"); +KTR_INFO(KTR_IF_EM, if_em, intr_end, 1, "intr end"); +KTR_INFO(KTR_IF_EM, if_em, pkt_receive, 4, "rx packet"); +KTR_INFO(KTR_IF_EM, if_em, pkt_txqueue, 5, "tx packet"); +KTR_INFO(KTR_IF_EM, if_em, pkt_txclean, 6, "tx clean"); #define logif(name) KTR_LOG(if_em_ ## name) static int diff --git a/sys/dev/netif/emx/if_emx.c b/sys/dev/netif/emx/if_emx.c index 1c57f61..e741f04 100644 --- a/sys/dev/netif/emx/if_emx.c +++ b/sys/dev/netif/emx/if_emx.c @@ -302,11 +302,11 @@ static int emx_display_debug_stats = 0; #define KTR_IF_EMX KTR_ALL #endif KTR_INFO_MASTER(if_emx); -KTR_INFO(KTR_IF_EMX, if_emx, intr_beg, 0, "intr begin", 0); -KTR_INFO(KTR_IF_EMX, if_emx, intr_end, 1, "intr end", 0); -KTR_INFO(KTR_IF_EMX, if_emx, pkt_receive, 4, "rx packet", 0); -KTR_INFO(KTR_IF_EMX, if_emx, pkt_txqueue, 5, "tx packet", 0); -KTR_INFO(KTR_IF_EMX, if_emx, pkt_txclean, 6, "tx clean", 0); +KTR_INFO(KTR_IF_EMX, if_emx, intr_beg, 0, "intr begin"); +KTR_INFO(KTR_IF_EMX, if_emx, intr_end, 1, "intr end"); +KTR_INFO(KTR_IF_EMX, if_emx, pkt_receive, 4, "rx packet"); +KTR_INFO(KTR_IF_EMX, if_emx, pkt_txqueue, 5, "tx packet"); +KTR_INFO(KTR_IF_EMX, if_emx, pkt_txclean, 6, "tx clean"); #define logif(name) KTR_LOG(if_emx_ ## name) static __inline void diff --git a/sys/kern/dsched/bfq/bfq_ktr.h b/sys/kern/dsched/bfq/bfq_ktr.h index 6941e68..54f6f13 100644 --- a/sys/kern/dsched/bfq/bfq_ktr.h +++ b/sys/kern/dsched/bfq/bfq_ktr.h @@ -52,13 +52,16 @@ KTR_INFO_MASTER(dsched_bfq); /* thread created */ -KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_created, 0, "%p", sizeof(void *)); +KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_created, 0, "%p", + struct bfq_thread_io *bfq_tdio); /* average seek distance per thread */ -KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_seek_avg, 0, "%p: %" PRIu64, sizeof(off_t) + sizeof(void *)); +KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_seek_avg, 0, "%p: %" PRIu64, + struct bfq_thread_io *bfq_tdio, off_t seek_avg); /* average thinking time per thread */ -KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_ttime_avg, 0, "%p: %" PRIu64, sizeof(off_t) + sizeof(void *)); +KTR_INFO(KTR_DSCHED_BFQ, dsched_bfq, thread_ttime_avg, 0, "%p: %" PRIu64, + struct bfq_thread_io *bfq_tdio, off_t ttime_avg); #endif diff --git a/sys/kern/kern_ktr.c b/sys/kern/kern_ktr.c index 10a207a..e4c819c 100644 --- a/sys/kern/kern_ktr.c +++ b/sys/kern/kern_ktr.c @@ -108,19 +108,19 @@ #endif KTR_INFO_MASTER(testlog); #if KTR_TESTLOG -KTR_INFO(KTR_TESTLOG, testlog, test1, 0, "test1", sizeof(void *) * 4); -KTR_INFO(KTR_TESTLOG, testlog, test2, 1, "test2", sizeof(void *) * 4); -KTR_INFO(KTR_TESTLOG, testlog, test3, 2, "test3", sizeof(void *) * 4); -KTR_INFO(KTR_TESTLOG, testlog, test4, 3, "test4", 0); -KTR_INFO(KTR_TESTLOG, testlog, test5, 4, "test5", 0); -KTR_INFO(KTR_TESTLOG, testlog, test6, 5, "test6", 0); +KTR_INFO(KTR_TESTLOG, testlog, test1, 0, "test1 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4); +KTR_INFO(KTR_TESTLOG, testlog, test2, 1, "test2 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4); +KTR_INFO(KTR_TESTLOG, testlog, test3, 2, "test3 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4); +KTR_INFO(KTR_TESTLOG, testlog, test4, 3, "test4"); +KTR_INFO(KTR_TESTLOG, testlog, test5, 4, "test5"); +KTR_INFO(KTR_TESTLOG, testlog, test6, 5, "test6"); #ifdef SMP -KTR_INFO(KTR_TESTLOG, testlog, pingpong, 6, "pingpong", 0); -KTR_INFO(KTR_TESTLOG, testlog, pipeline, 7, "pipeline", 0); -KTR_INFO(KTR_TESTLOG, testlog, crit_beg, 8, "crit_beg", 0); -KTR_INFO(KTR_TESTLOG, testlog, crit_end, 9, "crit_end", 0); -KTR_INFO(KTR_TESTLOG, testlog, spin_beg, 10, "spin_beg", 0); -KTR_INFO(KTR_TESTLOG, testlog, spin_end, 11, "spin_end", 0); +KTR_INFO(KTR_TESTLOG, testlog, pingpong, 6, "pingpong"); +KTR_INFO(KTR_TESTLOG, testlog, pipeline, 7, "pipeline"); +KTR_INFO(KTR_TESTLOG, testlog, crit_beg, 8, "crit_beg"); +KTR_INFO(KTR_TESTLOG, testlog, crit_end, 9, "crit_end"); +KTR_INFO(KTR_TESTLOG, testlog, spin_beg, 10, "spin_beg"); +KTR_INFO(KTR_TESTLOG, testlog, spin_end, 11, "spin_end"); #endif #define logtest(name) KTR_LOG(testlog_ ## name, 0, 0, 0, 0) #define logtest_noargs(name) KTR_LOG(testlog_ ## name) @@ -407,12 +407,11 @@ ktr_resync_callback(void *dummy __unused) #endif /* - * KTR_WRITE_ENTRY - Primary entry point for kernel trace logging + * Setup the next empty slot and return it to the caller to store the data + * directly. */ - -static __inline -void -ktr_write_entry(struct ktr_info *info, const char *file, int line, __va_list va) +struct ktr_entry * +ktr_begin_write_entry(struct ktr_info *info, const char *file, int line) { struct ktr_cpu_core *kcpu; struct ktr_entry *entry; @@ -421,7 +420,7 @@ ktr_write_entry(struct ktr_info *info, const char *file, int line, __va_list va) cpu = mycpu->gd_cpuid; kcpu = &ktr_cpu[cpu].core; if (kcpu->ktr_buf == NULL) - return; + return NULL; crit_enter(); entry = kcpu->ktr_buf + (kcpu->ktr_idx & KTR_ENTRIES_MASK); @@ -442,36 +441,26 @@ ktr_write_entry(struct ktr_info *info, const char *file, int line, __va_list va) entry->ktr_file = file; entry->ktr_line = line; crit_exit(); - if (info->kf_data_size > KTR_BUFSIZE) - bcopy(va, entry->ktr_data, KTR_BUFSIZE); - else if (info->kf_data_size) - bcopy(va, entry->ktr_data, info->kf_data_size); + return entry; +} + +int +ktr_finish_write_entry(struct ktr_info *info, struct ktr_entry *entry) +{ if (ktr_stacktrace) cpu_ktr_caller(entry); #ifdef KTR_VERBOSE if (ktr_verbose && info->kf_format) { #ifdef SMP - kprintf("cpu%d ", cpu); + kprintf("cpu%d ", mycpu->gd_cpuid); #endif if (ktr_verbose > 1) { kprintf("%s.%d\t", entry->ktr_file, entry->ktr_line); } - kvprintf(info->kf_format, va); - kprintf("\n"); + return !0; } #endif -} - -void -ktr_log(struct ktr_info *info, const char *file, int line, ...) -{ - __va_list va; - - if (panicstr == NULL) { - __va_start(va, line); - ktr_write_entry(info, file, line, va); - __va_end(va); - } + return 0; } #ifdef DDB diff --git a/sys/kern/kern_poll.c b/sys/kern/kern_poll.c index ae00c5b..a873f96 100644 --- a/sys/kern/kern_poll.c +++ b/sys/kern/kern_poll.c @@ -200,8 +200,8 @@ void init_device_poll_pcpu(int); /* per-cpu init routine */ #define KTR_POLLING KTR_ALL #endif KTR_INFO_MASTER(poll); -KTR_INFO(KTR_POLLING, poll, beg, 0, POLL_KTR_STRING, POLL_KTR_ARG_SIZE); -KTR_INFO(KTR_POLLING, poll, end, 1, POLL_KTR_STRING, POLL_KTR_ARG_SIZE); +KTR_INFO(KTR_POLLING, poll, beg, 0, "ifp=%p", void *ifp); +KTR_INFO(KTR_POLLING, poll, end, 1, "ifp=%p", void *ifp); #define logpoll(name, arg) KTR_LOG(poll_ ## name, arg) diff --git a/sys/kern/kern_slaballoc.c b/sys/kern/kern_slaballoc.c index 747ecc3..d9fdc88 100644 --- a/sys/kern/kern_slaballoc.c +++ b/sys/kern/kern_slaballoc.c @@ -119,27 +119,26 @@ #define btokup(z) (&pmap_kvtom((vm_offset_t)(z))->ku_pagecnt) -#define MEMORY_STRING "ptr=%p type=%p size=%d flags=%04x" -#define MEMORY_ARG_SIZE (sizeof(void *) * 2 + sizeof(unsigned long) + \ - sizeof(int)) +#define MEMORY_STRING "ptr=%p type=%p size=%lu flags=%04x" +#define MEMORY_ARGS void *ptr, void *type, unsigned long size, int flags #if !defined(KTR_MEMORY) #define KTR_MEMORY KTR_ALL #endif KTR_INFO_MASTER(memory); -KTR_INFO(KTR_MEMORY, memory, malloc_beg, 0, "malloc begin", 0); -KTR_INFO(KTR_MEMORY, memory, malloc_end, 1, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_zero, 2, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_ovsz, 3, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_ovsz_delayed, 4, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_chunk, 5, MEMORY_STRING, MEMORY_ARG_SIZE); +KTR_INFO(KTR_MEMORY, memory, malloc_beg, 0, "malloc begin"); +KTR_INFO(KTR_MEMORY, memory, malloc_end, 1, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_zero, 2, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_ovsz, 3, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_ovsz_delayed, 4, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_chunk, 5, MEMORY_STRING, MEMORY_ARGS); #ifdef SMP -KTR_INFO(KTR_MEMORY, memory, free_request, 6, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_rem_beg, 7, MEMORY_STRING, MEMORY_ARG_SIZE); -KTR_INFO(KTR_MEMORY, memory, free_rem_end, 8, MEMORY_STRING, MEMORY_ARG_SIZE); +KTR_INFO(KTR_MEMORY, memory, free_request, 6, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_rem_beg, 7, MEMORY_STRING, MEMORY_ARGS); +KTR_INFO(KTR_MEMORY, memory, free_rem_end, 8, MEMORY_STRING, MEMORY_ARGS); #endif -KTR_INFO(KTR_MEMORY, memory, free_beg, 9, "free begin", 0); -KTR_INFO(KTR_MEMORY, memory, free_end, 10, "free end", 0); +KTR_INFO(KTR_MEMORY, memory, free_beg, 9, "free begin"); +KTR_INFO(KTR_MEMORY, memory, free_end, 10, "free end"); #define logmemory(name, ptr, type, size, flags) \ KTR_LOG(memory_ ## name, ptr, type, size, flags) @@ -1011,7 +1010,7 @@ kfree_remote(void *ptr) KKASSERT(z->z_RCount > 0); atomic_subtract_int(&z->z_RCount, 1); - logmemory(free_rem_beg, z, NULL, 0, 0); + logmemory(free_rem_beg, z, NULL, 0L, 0); KKASSERT(z->z_Magic == ZALLOC_SLAB_MAGIC); KKASSERT(z->z_Cpu == mycpu->gd_cpuid); nfree = z->z_NFree; @@ -1078,7 +1077,7 @@ kfree_remote(void *ptr) kup = btokup(z); *kup = 0; } - logmemory(free_rem_end, z, bchunk, 0, 0); + logmemory(free_rem_end, z, bchunk, 0L, 0); } #endif @@ -1117,7 +1116,7 @@ kfree(void *ptr, struct malloc_type *type) * Handle special 0-byte allocations */ if (ptr == ZERO_LENGTH_PTR) { - logmemory(free_zero, ptr, type, -1, 0); + logmemory(free_zero, ptr, type, -1UL, 0); logmemory_quick(free_end); return; } @@ -1245,7 +1244,7 @@ kfree(void *ptr, struct malloc_type *type) * We can use a passive IPI to reduce overhead even further. */ if (bchunk == NULL && rsignal) { - logmemory(free_request, ptr, type, z->z_ChunkSize, 0); + logmemory(free_request, ptr, type, (unsigned long)z->z_ChunkSize, 0); lwkt_send_ipiq_passive(z->z_CpuGd, kfree_remote, z); /* z can get ripped out from under us from this point on */ } else if (rsignal) { @@ -1262,7 +1261,7 @@ kfree(void *ptr, struct malloc_type *type) /* * kfree locally */ - logmemory(free_chunk, ptr, type, z->z_ChunkSize, 0); + logmemory(free_chunk, ptr, type, (unsigned long)z->z_ChunkSize, 0); crit_enter(); chunk = ptr; diff --git a/sys/kern/kern_synch.c b/sys/kern/kern_synch.c index 959a514..4378085 100644 --- a/sys/kern/kern_synch.c +++ b/sys/kern/kern_synch.c @@ -93,11 +93,11 @@ MALLOC_DEFINE(M_TSLEEP, "tslpque", "tsleep queues"); #define KTR_TSLEEP KTR_ALL #endif KTR_INFO_MASTER(tsleep); -KTR_INFO(KTR_TSLEEP, tsleep, tsleep_beg, 0, "tsleep enter %p", sizeof(void *)); -KTR_INFO(KTR_TSLEEP, tsleep, tsleep_end, 1, "tsleep exit", 0); -KTR_INFO(KTR_TSLEEP, tsleep, wakeup_beg, 2, "wakeup enter %p", sizeof(void *)); -KTR_INFO(KTR_TSLEEP, tsleep, wakeup_end, 3, "wakeup exit", 0); -KTR_INFO(KTR_TSLEEP, tsleep, ilockfail, 4, "interlock failed %p", sizeof(void *)); +KTR_INFO(KTR_TSLEEP, tsleep, tsleep_beg, 0, "tsleep enter %p", const volatile void *ident); +KTR_INFO(KTR_TSLEEP, tsleep, tsleep_end, 1, "tsleep exit"); +KTR_INFO(KTR_TSLEEP, tsleep, wakeup_beg, 2, "wakeup enter %p", const volatile void *ident); +KTR_INFO(KTR_TSLEEP, tsleep, wakeup_end, 3, "wakeup exit"); +KTR_INFO(KTR_TSLEEP, tsleep, ilockfail, 4, "interlock failed %p", const volatile void *ident); #define logtsleep1(name) KTR_LOG(tsleep_ ## name) #define logtsleep2(name, val) KTR_LOG(tsleep_ ## name, val) diff --git a/sys/kern/lwkt_ipiq.c b/sys/kern/lwkt_ipiq.c index a2580aa..972458e 100644 --- a/sys/kern/lwkt_ipiq.c +++ b/sys/kern/lwkt_ipiq.c @@ -99,21 +99,21 @@ SYSCTL_INT(_lwkt, OID_AUTO, panic_ipiq_count, CTLFLAG_RW, &panic_ipiq_count, 0, #endif #define IPIQ_STRING "func=%p arg1=%p arg2=%d scpu=%d dcpu=%d" -#define IPIQ_ARG_SIZE (sizeof(void *) * 2 + sizeof(int) * 3) +#define IPIQ_ARGS void *func, void *arg1, int arg2, int scpu, int dcpu #if !defined(KTR_IPIQ) #define KTR_IPIQ KTR_ALL #endif KTR_INFO_MASTER(ipiq); -KTR_INFO(KTR_IPIQ, ipiq, send_norm, 0, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, send_pasv, 1, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, send_nbio, 2, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, send_fail, 3, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, receive, 4, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, sync_start, 5, "cpumask=%08x", sizeof(cpumask_t)); -KTR_INFO(KTR_IPIQ, ipiq, sync_end, 6, "cpumask=%08x", sizeof(cpumask_t)); -KTR_INFO(KTR_IPIQ, ipiq, cpu_send, 7, IPIQ_STRING, IPIQ_ARG_SIZE); -KTR_INFO(KTR_IPIQ, ipiq, send_end, 8, IPIQ_STRING, IPIQ_ARG_SIZE); +KTR_INFO(KTR_IPIQ, ipiq, send_norm, 0, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, send_pasv, 1, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, send_nbio, 2, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, send_fail, 3, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, receive, 4, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, sync_start, 5, "cpumask=%08lx", unsigned long mask); +KTR_INFO(KTR_IPIQ, ipiq, sync_end, 6, "cpumask=%08lx", unsigned long mask); +KTR_INFO(KTR_IPIQ, ipiq, cpu_send, 7, IPIQ_STRING, IPIQ_ARGS); +KTR_INFO(KTR_IPIQ, ipiq, send_end, 8, IPIQ_STRING, IPIQ_ARGS); #define logipiq(name, func, arg1, arg2, sgd, dgd) \ KTR_LOG(ipiq_ ## name, func, arg1, arg2, sgd->gd_cpuid, dgd->gd_cpuid) @@ -773,7 +773,7 @@ lwkt_cpusync_interlock(lwkt_cpusync_t cs) ++ipiq_cscount; ++gd->gd_curthread->td_cscount; lwkt_send_ipiq_mask(mask, (ipifunc1_t)lwkt_cpusync_remote1, cs); - logipiq2(sync_start, mask); + logipiq2(sync_start, (long)mask); #if 0 if (gd->gd_curthread->td_wmesg == NULL) gd->gd_curthread->td_wmesg = smsg; @@ -845,7 +845,7 @@ lwkt_cpusync_deinterlock(lwkt_cpusync_t cs) */ --gd->gd_curthread->td_cscount; lwkt_process_ipiq(); - logipiq2(sync_end, mask); + logipiq2(sync_end, (long)mask); } crit_exit_id("cpusync"); #else diff --git a/sys/kern/lwkt_serialize.c b/sys/kern/lwkt_serialize.c index e1e39b9..4e4b8ae 100644 --- a/sys/kern/lwkt_serialize.c +++ b/sys/kern/lwkt_serialize.c @@ -68,28 +68,28 @@ struct exp_backoff { }; #define SLZ_KTR_STRING "slz=%p" -#define SLZ_KTR_ARG_SIZE (sizeof(void *)) +#define SLZ_KTR_ARGS lwkt_serialize_t slz #ifndef KTR_SERIALIZER #define KTR_SERIALIZER KTR_ALL #endif KTR_INFO_MASTER(slz); -KTR_INFO(KTR_SERIALIZER, slz, enter_beg, 0, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, sleep_beg, 1, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, sleep_end, 2, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, exit_end, 3, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, wakeup_beg, 4, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, wakeup_end, 5, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, try, 6, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, tryfail, 7, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, tryok, 8, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); +KTR_INFO(KTR_SERIALIZER, slz, enter_beg, 0, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, sleep_beg, 1, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, sleep_end, 2, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, exit_end, 3, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, wakeup_beg, 4, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, wakeup_end, 5, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, try, 6, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, tryfail, 7, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, tryok, 8, SLZ_KTR_STRING, SLZ_KTR_ARGS); #ifdef SMP KTR_INFO(KTR_SERIALIZER, slz, spinbo, 9, - "slz=%p bo1=%d bo=%d", (sizeof(void *) + (2 * sizeof(int)))); + "slz=%p bo1=%d bo=%d", lwkt_serialize_t slz, int backoff1, int backoff); #endif -KTR_INFO(KTR_SERIALIZER, slz, enter_end, 10, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); -KTR_INFO(KTR_SERIALIZER, slz, exit_beg, 11, SLZ_KTR_STRING, SLZ_KTR_ARG_SIZE); +KTR_INFO(KTR_SERIALIZER, slz, enter_end, 10, SLZ_KTR_STRING, SLZ_KTR_ARGS); +KTR_INFO(KTR_SERIALIZER, slz, exit_beg, 11, SLZ_KTR_STRING, SLZ_KTR_ARGS); #define logslz(name, slz) KTR_LOG(slz_ ## name, slz) #ifdef SMP diff --git a/sys/kern/lwkt_thread.c b/sys/kern/lwkt_thread.c index 7ebfcb2..389d1f0 100644 --- a/sys/kern/lwkt_thread.c +++ b/sys/kern/lwkt_thread.c @@ -76,13 +76,10 @@ #define KTR_CTXSW KTR_ALL #endif KTR_INFO_MASTER(ctxsw); -KTR_INFO(KTR_CTXSW, ctxsw, sw, 0, "#cpu[%d].td = %p", - sizeof(int) + sizeof(struct thread *)); -KTR_INFO(KTR_CTXSW, ctxsw, pre, 1, "#cpu[%d].td = %p", - sizeof(int) + sizeof(struct thread *)); -KTR_INFO(KTR_CTXSW, ctxsw, newtd, 2, "#threads[%p].name = %s", - sizeof (struct thread *) + sizeof(char *)); -KTR_INFO(KTR_CTXSW, ctxsw, deadtd, 3, "#threads[%p].name = ", sizeof (struct thread *)); +KTR_INFO(KTR_CTXSW, ctxsw, sw, 0, "#cpu[%d].td = %p", int cpu, struct thread *td); +KTR_INFO(KTR_CTXSW, ctxsw, pre, 1, "#cpu[%d].td = %p", int cpu, struct thread *td); +KTR_INFO(KTR_CTXSW, ctxsw, newtd, 2, "#threads[%p].name = %s", struct thread *td, char *comm); +KTR_INFO(KTR_CTXSW, ctxsw, deadtd, 3, "#threads[%p].name = ", struct thread *td); static MALLOC_DEFINE(M_THREAD, "thread", "lwkt threads"); @@ -523,7 +520,7 @@ lwkt_set_comm(thread_t td, const char *ctl, ...) __va_start(va, ctl); kvsnprintf(td->td_comm, sizeof(td->td_comm), ctl, va); __va_end(va); - KTR_LOG(ctxsw_newtd, td, &td->td_comm[0]); + KTR_LOG(ctxsw_newtd, td, td->td_comm); } /* diff --git a/sys/kern/lwkt_token.c b/sys/kern/lwkt_token.c index 3149450..37ae5b9 100644 --- a/sys/kern/lwkt_token.c +++ b/sys/kern/lwkt_token.c @@ -85,23 +85,24 @@ extern int lwkt_sched_debug; static lwkt_token pool_tokens[LWKT_NUM_POOL_TOKENS]; #define TOKEN_STRING "REF=%p TOK=%p TD=%p" -#define CONTENDED_STRING "REF=%p TOK=%p TD=%p (contention started)" -#define UNCONTENDED_STRING "REF=%p TOK=%p TD=%p (contention stopped)" +#define TOKEN_ARGS lwkt_tokref_t ref, lwkt_token_t tok, struct thread *td +#define CONTENDED_STRING TOKEN_STRING " (contention started)" +#define UNCONTENDED_STRING TOKEN_STRING " (contention stopped)" #if !defined(KTR_TOKENS) #define KTR_TOKENS KTR_ALL #endif KTR_INFO_MASTER(tokens); -KTR_INFO(KTR_TOKENS, tokens, fail, 0, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, succ, 1, TOKEN_STRING, sizeof(void *) * 3); +KTR_INFO(KTR_TOKENS, tokens, fail, 0, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, succ, 1, TOKEN_STRING, TOKEN_ARGS); #if 0 -KTR_INFO(KTR_TOKENS, tokens, release, 2, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, remote, 3, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, reqremote, 4, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, reqfail, 5, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, drain, 6, TOKEN_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, contention_start, 7, CONTENDED_STRING, sizeof(void *) * 3); -KTR_INFO(KTR_TOKENS, tokens, contention_stop, 7, UNCONTENDED_STRING, sizeof(void *) * 3); +KTR_INFO(KTR_TOKENS, tokens, release, 2, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, remote, 3, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, reqremote, 4, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, reqfail, 5, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, drain, 6, TOKEN_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, contention_start, 7, CONTENDED_STRING, TOKEN_ARGS); +KTR_INFO(KTR_TOKENS, tokens, contention_stop, 7, UNCONTENDED_STRING, TOKEN_ARGS); #endif #define logtoken(name, ref) \ diff --git a/sys/net/if.c b/sys/net/if.c index 967a2af..07cfc6c 100644 --- a/sys/net/if.c +++ b/sys/net/if.c @@ -175,32 +175,32 @@ struct ifnet **ifindex2ifnet = NULL; static struct thread ifnet_threads[MAXCPU]; #define IFQ_KTR_STRING "ifq=%p" -#define IFQ_KTR_ARG_SIZE (sizeof(void *)) +#define IFQ_KTR_ARGS struct ifaltq *ifq #ifndef KTR_IFQ #define KTR_IFQ KTR_ALL #endif KTR_INFO_MASTER(ifq); -KTR_INFO(KTR_IFQ, ifq, enqueue, 0, IFQ_KTR_STRING, IFQ_KTR_ARG_SIZE); -KTR_INFO(KTR_IFQ, ifq, dequeue, 1, IFQ_KTR_STRING, IFQ_KTR_ARG_SIZE); +KTR_INFO(KTR_IFQ, ifq, enqueue, 0, IFQ_KTR_STRING, IFQ_KTR_ARGS); +KTR_INFO(KTR_IFQ, ifq, dequeue, 1, IFQ_KTR_STRING, IFQ_KTR_ARGS); #define logifq(name, arg) KTR_LOG(ifq_ ## name, arg) #define IF_START_KTR_STRING "ifp=%p" -#define IF_START_KTR_ARG_SIZE (sizeof(void *)) +#define IF_START_KTR_ARGS struct ifnet *ifp #ifndef KTR_IF_START #define KTR_IF_START KTR_ALL #endif KTR_INFO_MASTER(if_start); KTR_INFO(KTR_IF_START, if_start, run, 0, - IF_START_KTR_STRING, IF_START_KTR_ARG_SIZE); + IF_START_KTR_STRING, IF_START_KTR_ARGS); KTR_INFO(KTR_IF_START, if_start, sched, 1, - IF_START_KTR_STRING, IF_START_KTR_ARG_SIZE); + IF_START_KTR_STRING, IF_START_KTR_ARGS); KTR_INFO(KTR_IF_START, if_start, avoid, 2, - IF_START_KTR_STRING, IF_START_KTR_ARG_SIZE); + IF_START_KTR_STRING, IF_START_KTR_ARGS); KTR_INFO(KTR_IF_START, if_start, contend_sched, 3, - IF_START_KTR_STRING, IF_START_KTR_ARG_SIZE); + IF_START_KTR_STRING, IF_START_KTR_ARGS); #ifdef SMP KTR_INFO(KTR_IF_START, if_start, chase_sched, 4, - IF_START_KTR_STRING, IF_START_KTR_ARG_SIZE); + IF_START_KTR_STRING, IF_START_KTR_ARGS); #endif #define logifstart(name, arg) KTR_LOG(if_start_ ## name, arg) diff --git a/sys/net/if_ethersubr.c b/sys/net/if_ethersubr.c index 4c5a652..7103289 100644 --- a/sys/net/if_ethersubr.c +++ b/sys/net/if_ethersubr.c @@ -180,15 +180,15 @@ SYSCTL_ULONG(_net_link_ether, OID_AUTO, input_requeue, CTLFLAG_RW, #endif #define ETHER_KTR_STR "ifp=%p" -#define ETHER_KTR_ARG_SIZE (sizeof(void *)) +#define ETHER_KTR_ARGS struct ifnet *ifp #ifndef KTR_ETHERNET #define KTR_ETHERNET KTR_ALL #endif KTR_INFO_MASTER(ether); -KTR_INFO(KTR_ETHERNET, ether, chain_beg, 0, ETHER_KTR_STR, ETHER_KTR_ARG_SIZE); -KTR_INFO(KTR_ETHERNET, ether, chain_end, 1, ETHER_KTR_STR, ETHER_KTR_ARG_SIZE); -KTR_INFO(KTR_ETHERNET, ether, disp_beg, 2, ETHER_KTR_STR, ETHER_KTR_ARG_SIZE); -KTR_INFO(KTR_ETHERNET, ether, disp_end, 3, ETHER_KTR_STR, ETHER_KTR_ARG_SIZE); +KTR_INFO(KTR_ETHERNET, ether, chain_beg, 0, ETHER_KTR_STR, ETHER_KTR_ARGS); +KTR_INFO(KTR_ETHERNET, ether, chain_end, 1, ETHER_KTR_STR, ETHER_KTR_ARGS); +KTR_INFO(KTR_ETHERNET, ether, disp_beg, 2, ETHER_KTR_STR, ETHER_KTR_ARGS); +KTR_INFO(KTR_ETHERNET, ether, disp_end, 3, ETHER_KTR_STR, ETHER_KTR_ARGS); #define logether(name, arg) KTR_LOG(ether_ ## name, arg) /* diff --git a/sys/platform/pc32/i386/trap.c b/sys/platform/pc32/i386/trap.c index 35d1e24..724806f 100644 --- a/sys/platform/pc32/i386/trap.c +++ b/sys/platform/pc32/i386/trap.c @@ -370,16 +370,17 @@ userexit(struct lwp *lp) #define KTR_KERNENTRY KTR_ALL #endif KTR_INFO_MASTER(kernentry); -KTR_INFO(KTR_KERNENTRY, kernentry, trap, 0, "pid=%d, tid=%d, trapno=%d, eva=%p", - sizeof(int) + sizeof(int) + sizeof(int) + sizeof(vm_offset_t)); -KTR_INFO(KTR_KERNENTRY, kernentry, trap_ret, 0, "pid=%d, tid=%d", - sizeof(int) + sizeof(int)); -KTR_INFO(KTR_KERNENTRY, kernentry, syscall, 0, "pid=%d, tid=%d, call=%d", - sizeof(int) + sizeof(int) + sizeof(int)); -KTR_INFO(KTR_KERNENTRY, kernentry, syscall_ret, 0, "pid=%d, tid=%d, err=%d", - sizeof(int) + sizeof(int) + sizeof(int)); -KTR_INFO(KTR_KERNENTRY, kernentry, fork_ret, 0, "pid=%d, tid=%d", - sizeof(int) + sizeof(int)); +KTR_INFO(KTR_KERNENTRY, kernentry, trap, 0, + "TRAP(pid %d, tid %d, trapno %d, eva %lu)", + pid_t pid, lwpid_t tid, register_t trapno, vm_offset_t eva); +KTR_INFO(KTR_KERNENTRY, kernentry, trap_ret, 0, "TRAP_RET(pid %d, tid %d)", + pid_t pid, lwpid_t tid); +KTR_INFO(KTR_KERNENTRY, kernentry, syscall, 0, "SYSC(pid %d, tid %d, nr %d)", + pid_t pid, lwpid_t tid, register_t trapno); +KTR_INFO(KTR_KERNENTRY, kernentry, syscall_ret, 0, "SYSRET(pid %d, tid %d, err %d)", + pid_t pid, lwpid_t tid, int err); +KTR_INFO(KTR_KERNENTRY, kernentry, fork_ret, 0, "FORKRET(pid %d, tid %d)", + pid_t pid, lwpid_t tid); /* * Exception, fault, and trap interface to the kernel. diff --git a/sys/platform/pc64/x86_64/trap.c b/sys/platform/pc64/x86_64/trap.c index 70c48c1..f74bc24 100644 --- a/sys/platform/pc64/x86_64/trap.c +++ b/sys/platform/pc64/x86_64/trap.c @@ -356,16 +356,17 @@ userexit(struct lwp *lp) #define KTR_KERNENTRY KTR_ALL #endif KTR_INFO_MASTER(kernentry); -KTR_INFO(KTR_KERNENTRY, kernentry, trap, 0, "STR", - sizeof(long) + sizeof(long) + sizeof(long) + sizeof(vm_offset_t)); -KTR_INFO(KTR_KERNENTRY, kernentry, trap_ret, 0, "STR", - sizeof(long) + sizeof(long)); -KTR_INFO(KTR_KERNENTRY, kernentry, syscall, 0, "STR", - sizeof(long) + sizeof(long) + sizeof(long)); -KTR_INFO(KTR_KERNENTRY, kernentry, syscall_ret, 0, "STR", - sizeof(long) + sizeof(long) + sizeof(long)); -KTR_INFO(KTR_KERNENTRY, kernentry, fork_ret, 0, "STR", - sizeof(long) + sizeof(long)); +KTR_INFO(KTR_KERNENTRY, kernentry, trap, 0, + "TRAP(pid %hd, tid %hd, trapno %ld, eva %lu)", + pid_t pid, lwpid_t tid, register_t trapno, vm_offset_t eva); +KTR_INFO(KTR_KERNENTRY, kernentry, trap_ret, 0, "TRAP_RET(pid %hd, tid %hd)", + pid_t pid, lwpid_t tid); +KTR_INFO(KTR_KERNENTRY, kernentry, syscall, 0, "SYSC(pid %hd, tid %hd, nr %ld)", + pid_t pid, lwpid_t tid, register_t trapno); +KTR_INFO(KTR_KERNENTRY, kernentry, syscall_ret, 0, "SYSRET(pid %hd, tid %hd, err %d)", + pid_t pid, lwpid_t tid, int err); +KTR_INFO(KTR_KERNENTRY, kernentry, fork_ret, 0, "FORKRET(pid %hd, tid %hd)", + pid_t pid, lwpid_t tid); /* * Exception, fault, and trap interface to the kernel. diff --git a/sys/sys/ktr.h b/sys/sys/ktr.h index 48b1ad3..8becde3 100644 --- a/sys/sys/ktr.h +++ b/sys/sys/ktr.h @@ -39,12 +39,9 @@ #ifndef _SYS_KTR_H_ #define _SYS_KTR_H_ -#ifndef _SYS_TYPES_H_ #include -#endif -#ifndef _SYS_SYSCTL_H_ #include -#endif +#include #ifdef _KERNEL #include "opt_ktr.h" @@ -74,7 +71,7 @@ struct ktr_info { const char *kf_name; /* human-interpreted subsystem name */ int32_t *kf_master_enable; /* the master enable variable */ - const char *kf_format; /* data format */ + const char * const kf_format; /* data format */ int kf_data_size; /* relevance of the data buffer */ }; @@ -101,7 +98,9 @@ struct ktr_cpu { #ifdef _KERNEL -void ktr_log(struct ktr_info *info, const char *file, int line, ...); +struct ktr_entry * ktr_begin_write_entry(struct ktr_info *, + const char *, int); +int ktr_finish_write_entry(struct ktr_info *, struct ktr_entry *); void cpu_ktr_caller(struct ktr_entry *ktr); #endif @@ -132,27 +131,71 @@ SYSCTL_DECL(_debug_ktr); * definitions are and a number of static const int's which are used * by the compiler to optimize the trace logging at compile-time and * run-time. + * You're supposed to specify any arguments to the format as you would in + * a function prototype. + * We automagically create a struct for the arguments and a throwaway + * function that will be called with the format and the actual arguments + * at the KTR_LOG site. This makes sure that the compiler will typecheck + * the arguments against the format string. On gcc, this requires -Wformat + * (which is included in -Wall) and -O1 at least. Note that using + * ktr_info.kf_format will not work, hence we need to define another + * throwaway const wariable for the format. */ -#define KTR_INFO(compile, master, name, maskbit, format, datasize) \ - static const int ktr_ ## master ## _ ## name ## _mask = \ - 1 << maskbit; \ - static const int ktr_ ## master ## _ ## name ## _enable = \ +#define KTR_INFO(compile, master, name, maskbit, format, ...) \ + static const int ktr_ ## master ## _ ## name ## _mask = \ + 1 << (maskbit); \ + static const int ktr_ ## master ## _ ##name ## _enable = \ compile; \ - static int ktr_ ## master ## _ ## name ## _mask_ro = \ - 1 << maskbit; \ - SYSCTL_INT(_debug_ktr_ ## master, OID_AUTO, name ## _mask, \ - CTLFLAG_RD, &ktr_ ## master ## _ ## name ## _mask_ro, \ - 0, "Value of the " __XSTRING(name) " event in " __XSTRING(master) "'s mask"); \ - static struct ktr_info ktr_info_ ## master ## _ ## name = { \ - #master "_" #name, \ - &ktr_ ## master ## _enable, \ - format, \ - datasize } - -#define KTR_LOG(name, args...) \ - if (ktr_ ## name ## _enable && \ - (ktr_ ## name ## _mask & *ktr_info_ ## name .kf_master_enable)) \ - ktr_log(&ktr_info_ ## name, __FILE__, __LINE__, ##args) + static int ktr_ ## master ## _ ## name ## _mask_ro = \ + 1 << (maskbit); \ + SYSCTL_INT(_debug_ktr_ ## master, OID_AUTO, name ## _mask, \ + CTLFLAG_RD, &ktr_ ## master ## _ ## name ## _mask_ro, \ + 0, "Value of the " __XSTRING(name) " event in " __XSTRING(master) "'s mask"); \ + __GENSTRUCT(ktr_info_ ## master ## _ ## name ## _args, __VA_ARGS__) \ + __packed; \ + CTASSERT(sizeof(struct ktr_info_ ## master ## _ ## name ## _args) <= KTR_BUFSIZE); \ + static inline void \ + __ktr_info_ ## master ## _ ## name ## _fmtcheck(const char *fmt, \ + ...) __printf0like(1, 2); \ + static inline void \ + __ktr_info_ ## master ## _ ## name ## _fmtcheck(const char *fmt __unused, \ + ...) \ + {} \ + static const char * const __ktr_ ## master ## _ ## name ## _fmt = format; \ + static struct ktr_info ktr_info_ ## master ## _ ## name = { \ + .kf_name = #master "_" #name, \ + .kf_master_enable = &ktr_ ## master ## _enable, \ + .kf_format = format, \ + .kf_data_size = sizeof(struct ktr_info_ ## master ## _ ## name ## _args), \ + } + + + + +/* + * Call ktr_begin_write_entry() that sets up the entry for us; use + * a struct copy to give as max flexibility as possible to the compiler. + * In higher optimization levels, it will copy the arguments directly from + * registers to the destination buffer. Call our dummy function that will + * typecheck the arguments against the format string. + */ +#define KTR_LOG(name, ...) \ + do { \ + __ktr_info_ ## name ## _fmtcheck (__ktr_ ## name ## _fmt, ##__VA_ARGS__); \ + if (ktr_ ## name ## _enable && \ + (ktr_ ## name ## _mask & *ktr_info_ ## name .kf_master_enable)) { \ + struct ktr_entry *entry; \ + entry = ktr_begin_write_entry(&ktr_info_ ## name, __FILE__, __LINE__); \ + if (!entry) \ + break; \ + *(struct ktr_info_ ## name ## _args *)&entry->ktr_data[0] = \ + (struct ktr_info_ ## name ## _args){ __VA_ARGS__}; \ + if (ktr_finish_write_entry(&ktr_info_ ## name, entry)) { \ + kprintf(ktr_info_ ## name .kf_format, ##__VA_ARGS__); \ + kprintf("\n"); \ + } \ + } \ + } while(0) #else @@ -162,9 +205,9 @@ SYSCTL_DECL(_debug_ktr); #define KTR_INFO_MASTER_EXTERN(master) \ static const int ktr_ ## master ## _enable -#define KTR_INFO(compile, master, name, maskbit, format, datasize) \ +#define KTR_INFO(compile, master, name, maskbit, format, ...) \ static const int ktr_ ## master ## _ ## name ## _mask = \ - 1 << maskbit + (1 << maskbit) #define KTR_LOG(info, args...) -- 1.7.7.2