From 8d0f1ee907d425e71e34e1aea9c1b5465f8cd4d1 Mon Sep 17 00:00:00 2001 From: behlendo Date: Mon, 31 Mar 2008 20:42:36 +0000 Subject: [PATCH] Add some crude debugging support. It leaves alot to be desired, but it should allow more easy kernel debugging for now. git-svn-id: https://outreach.scidac.gov/svn/spl/trunk@59 7e1ea52c-4ff2-0310-8f11-9dd32ca42a1c --- include/sys/debug.h | 7 ++ include/sys/kmem.h | 6 +- include/sys/rwlock.h | 2 +- include/sys/sysmacros.h | 2 +- modules/spl/spl-generic.c | 222 +++++++++++++++++++++++++++++++-- modules/spl/spl-kmem.c | 4 +- modules/spl/spl-thread.c | 2 +- modules/spl/spl-vnode.c | 11 +- modules/splat/splat-internal.h | 36 +++--- 9 files changed, 251 insertions(+), 41 deletions(-) diff --git a/include/sys/debug.h b/include/sys/debug.h index 02f64c2cf..4a6ed5c3d 100644 --- a/include/sys/debug.h +++ b/include/sys/debug.h @@ -1,4 +1,11 @@ #ifndef _SPL_DEBUG_H #define _SPL_DEBUG_H +extern unsigned long spl_debug_mask; +extern unsigned long spl_debug_subsys; + +void __dprintf(const char *file, const char *func, int line, const char *fmt, ...); +void spl_set_debug_mask(unsigned long mask); +void spl_set_debug_subsys(unsigned long mask); + #endif /* SPL_DEBUG_H */ diff --git a/include/sys/kmem.h b/include/sys/kmem.h index 46322105d..58ae07747 100644 --- a/include/sys/kmem.h +++ b/include/sys/kmem.h @@ -35,14 +35,14 @@ extern int kmem_warning_flag; \ /* Marked unlikely because we should never be doing this */ \ if (unlikely((size) > (PAGE_SIZE * 2)) && kmem_warning_flag) \ - printk("Warning: kmem_alloc(%d, 0x%x) large alloc at %s:%d " \ + printk("spl: Warning kmem_alloc(%d, 0x%x) large alloc at %s:%d " \ "(%ld/%ld)\n", (int)(size), (int)(flags), \ __FILE__, __LINE__, \ atomic64_read(&kmem_alloc_used), kmem_alloc_max); \ \ _ptr_ = (void *)allocator((size), (flags)); \ if (_ptr_ == NULL) { \ - printk("Warning: kmem_alloc(%d, 0x%x) failed at %s:%d " \ + printk("spl: Warning kmem_alloc(%d, 0x%x) failed at %s:%d " \ "(%ld/%ld)\n", (int)(size), (int)(flags), \ __FILE__, __LINE__, \ atomic64_read(&kmem_alloc_used), kmem_alloc_max); \ @@ -73,7 +73,7 @@ extern int kmem_warning_flag; \ _ptr_ = (void *)vmalloc((size)); \ if (_ptr_ == NULL) { \ - printk("Warning: vmem_alloc(%d, 0x%x) failed at %s:%d " \ + printk("spl: Warning vmem_alloc(%d, 0x%x) failed at %s:%d " \ "(%ld/%ld)\n", (int)(size), (int)(flags), \ __FILE__, __LINE__, \ atomic64_read(&vmem_alloc_used), vmem_alloc_max); \ diff --git a/include/sys/rwlock.h b/include/sys/rwlock.h index ecee07948..6407e632d 100644 --- a/include/sys/rwlock.h +++ b/include/sys/rwlock.h @@ -236,7 +236,7 @@ rw_tryupgrade(krwlock_t *rwlp) * lock. If there is, then we know we should * not try to upgrade the lock */ if (!list_empty(&rwlp->rw_sem.wait_list)) { - printk(KERN_WARNING "There are threads waiting\n"); + printk("spl: Warning There are threads waiting\n"); spin_unlock(&rwlp->rw_sem.wait_lock); return 0; } diff --git a/include/sys/sysmacros.h b/include/sys/sysmacros.h index a64950d10..d5f8597c2 100644 --- a/include/sys/sysmacros.h +++ b/include/sys/sysmacros.h @@ -80,7 +80,7 @@ extern "C" { const TYPE __left = (TYPE)(LEFT); \ const TYPE __right = (TYPE)(RIGHT); \ if (!(__left OP __right)) { \ - printk("Failed VERIFY3(" FMT " " #OP " " FMT ")\n", \ + printk("spl: Error VERIFY3(" FMT " " #OP " " FMT ")\n", \ CAST __left, CAST __right); \ BUG(); \ } \ diff --git a/modules/spl/spl-generic.c b/modules/spl/spl-generic.c index 2773ff689..3c958f518 100644 --- a/modules/spl/spl-generic.c +++ b/modules/spl/spl-generic.c @@ -2,11 +2,24 @@ #include #include #include +#include +#include #include "config.h" /* * Generic support */ +static char spl_debug_buffer[MAXMSGLEN]; +static spinlock_t spl_debug_lock = SPIN_LOCK_UNLOCKED; + +unsigned long spl_debug_mask = 0; +unsigned long spl_debug_subsys = 0xff; +EXPORT_SYMBOL(spl_debug_mask); +EXPORT_SYMBOL(spl_debug_subsys); + +static struct proc_dir_entry *spl_proc_root = NULL; +static struct proc_dir_entry *spl_proc_debug_mask = NULL; +static struct proc_dir_entry *spl_proc_debug_subsys = NULL; int p0 = 0; EXPORT_SYMBOL(p0); @@ -17,6 +30,7 @@ EXPORT_SYMBOL(hw_serial); vmem_t *zio_alloc_arena = NULL; EXPORT_SYMBOL(zio_alloc_arena); + int highbit(unsigned long i) { @@ -56,27 +70,221 @@ ddi_strtoul(const char *str, char **nptr, int base, unsigned long *result) } EXPORT_SYMBOL(ddi_strtoul); -static int __init spl_init(void) +/* XXX: Not the most efficient debug function ever. This should be re-done + * as an internal per-cpu in-memory debug log accessable via /proc/. Not as + * a shared global buffer everything gets serialize though. That said I'll + * worry about performance considerations once I've dealt with correctness. + */ +void +__dprintf(const char *file, const char *func, int line, const char *fmt, ...) +{ + char *sfp, *start, *ptr; + struct timeval tv; + va_list ap; + + start = ptr = spl_debug_buffer; + sfp = strrchr(file, '/'); + do_gettimeofday(&tv); + + spin_lock(&spl_debug_lock); + ptr += snprintf(ptr, MAXMSGLEN - 1, + "spl: %lu.%06lu:%d:%u:%s:%d:%s(): ", + tv.tv_sec, tv.tv_usec, current->pid, + smp_processor_id(), + sfp == NULL ? file : sfp + 1, + line, func); + + va_start(ap, fmt); + ptr += vsnprintf(ptr, MAXMSGLEN - (ptr - start) - 1, fmt, ap); + va_end(ap); + + printk("%s", start); + spin_unlock(&spl_debug_lock); +} +EXPORT_SYMBOL(__dprintf); + +static int +spl_proc_rd_generic_ul(char *page, char **start, off_t off, + int count, int *eof, unsigned long val) { int rc; - if ((rc = kmem_init())) - return rc; + *start = page; + *eof = 1; - if ((rc = vn_init())) - return rc; + if (off || count > PAGE_SIZE) + return 0; - strcpy(hw_serial, "007f0100"); /* loopback */ - printk(KERN_INFO "spl: Loaded Solaris Porting Layer v%s\n", VERSION); + spin_lock(&spl_debug_lock); + rc = snprintf(page, PAGE_SIZE, "0x%lx\n", val); + spin_unlock(&spl_debug_lock); + + return rc; +} + +static int +spl_proc_rd_debug_mask(char *page, char **start, off_t off, + int count, int *eof, void *data) +{ + return spl_proc_rd_generic_ul(page, start, off, count, + eof, spl_debug_mask); +} + +static int +spl_proc_rd_debug_subsys(char *page, char **start, off_t off, + int count, int *eof, void *data) +{ + return spl_proc_rd_generic_ul(page, start, off, count, + eof, spl_debug_subsys); +} + +static int +spl_proc_wr_generic_ul(const char *ubuf, unsigned long count, + unsigned long *val, int base) +{ + char *end, kbuf[32]; + + if (count >= sizeof(kbuf)) + return -EOVERFLOW; + + if (copy_from_user(kbuf, ubuf, count)) + return -EFAULT; + + kbuf[count] = '\0'; + *val = (int)simple_strtoul(kbuf, &end, base); + if (kbuf == end) + return -EINVAL; return 0; } +static int +spl_proc_wr_debug_mask(struct file *file, const char *ubuf, + unsigned long count, void *data, int mode) +{ + unsigned long val; + int rc; + + rc = spl_proc_wr_generic_ul(ubuf, count, &val, 16); + if (rc) + return rc; + + spin_lock(&spl_debug_lock); + spl_debug_mask = val; + spin_unlock(&spl_debug_lock); + + return count; +} + +static int +spl_proc_wr_debug_subsys(struct file *file, const char *ubuf, + unsigned long count, void *data, int mode) +{ + unsigned long val; + int rc; + + rc = spl_proc_wr_generic_ul(ubuf, count, &val, 16); + if (rc) + return rc; + + spin_lock(&spl_debug_lock); + spl_debug_subsys = val; + spin_unlock(&spl_debug_lock); + + return count; +} + +static struct proc_dir_entry * +spl_register_proc_entry(const char *name, mode_t mode, + struct proc_dir_entry *parent, void *data, + void *read_proc, void *write_proc) +{ + struct proc_dir_entry *entry; + + entry = create_proc_entry(name, mode, parent); + if (!entry) + return ERR_PTR(-EINVAL); + + entry->data = data; + entry->read_proc = read_proc; + entry->write_proc = write_proc; + + return entry; +} /* register_proc_entry() */ + +void spl_set_debug_mask(unsigned long mask) { + spin_lock(&spl_debug_lock); + spl_debug_mask = mask; + spin_unlock(&spl_debug_lock); +} +EXPORT_SYMBOL(spl_set_debug_mask); + +void spl_set_debug_subsys(unsigned long mask) { + spin_lock(&spl_debug_lock); + spl_debug_subsys = mask; + spin_unlock(&spl_debug_lock); +} +EXPORT_SYMBOL(spl_set_debug_subsys); + +static int __init spl_init(void) +{ + int rc = 0; + + spl_proc_root = proc_mkdir("spl", NULL); + if (!spl_proc_root) { + printk("spl: Error unable to create /proc/spl/ directory\n"); + return -EINVAL; + } + + spl_proc_debug_mask = spl_register_proc_entry("debug_mask", 0644, + spl_proc_root, NULL, + spl_proc_rd_debug_mask, + spl_proc_wr_debug_mask); + if (IS_ERR(spl_proc_debug_mask)) { + rc = PTR_ERR(spl_proc_debug_mask); + goto out; + } + + spl_proc_debug_subsys = spl_register_proc_entry("debug_subsys", 0644, + spl_proc_root, NULL, + spl_proc_rd_debug_subsys, + spl_proc_wr_debug_subsys); + if (IS_ERR(spl_proc_debug_subsys)) { + rc = PTR_ERR(spl_proc_debug_subsys); + goto out2; + } + + if ((rc = kmem_init())) + goto out2; + + if ((rc = vn_init())) + goto out2; + + strcpy(hw_serial, "007f0100"); /* loopback */ + printk("spl: Loaded Solaris Porting Layer v%s\n", VERSION); + + return 0; +out2: + if (spl_proc_debug_mask) + remove_proc_entry("debug_mask", spl_proc_root); + + if (spl_proc_debug_subsys) + remove_proc_entry("debug_subsys", spl_proc_root); +out: + remove_proc_entry("spl", NULL); + + return rc; +} + static void spl_fini(void) { vn_fini(); kmem_fini(); + remove_proc_entry("debug_subsys", spl_proc_root); + remove_proc_entry("debug_mask", spl_proc_root); + remove_proc_entry("spl", NULL); + return; } diff --git a/modules/spl/spl-kmem.c b/modules/spl/spl-kmem.c index a1f3b54e2..08387d0d8 100644 --- a/modules/spl/spl-kmem.c +++ b/modules/spl/spl-kmem.c @@ -291,11 +291,11 @@ kmem_fini(void) { #ifdef DEBUG_KMEM if (atomic64_read(&kmem_alloc_used) != 0) - printk("Warning: kmem leaked %ld/%ld bytes\n", + printk("spl: Warning kmem leaked %ld/%ld bytes\n", atomic_read(&kmem_alloc_used), kmem_alloc_max); if (atomic64_read(&vmem_alloc_used) != 0) - printk("Warning: vmem leaked %ld/%ld bytes\n", + printk("spl: Warning vmem leaked %ld/%ld bytes\n", atomic_read(&vmem_alloc_used), vmem_alloc_max); #endif } diff --git a/modules/spl/spl-thread.c b/modules/spl/spl-thread.c index a2c72f051..ad90e0720 100644 --- a/modules/spl/spl-thread.c +++ b/modules/spl/spl-thread.c @@ -90,7 +90,7 @@ __thread_create(caddr_t stk, size_t stksize, thread_func_t func, /* Solaris says this must never fail so we try forever */ while ((pid = kernel_thread(thread_generic_wrapper, (void *)&tp, 0)) < 0) - printk(KERN_ERR "Unable to create thread; pid = %ld\n", pid); + printk(KERN_ERR "spl: Error unable to create thread; pid = %ld\n", pid); /* All signals are ignored due to sleeping TASK_UNINTERRUPTIBLE */ for (;;) { diff --git a/modules/spl/spl-vnode.c b/modules/spl/spl-vnode.c index 24ee71293..401c6e0e8 100644 --- a/modules/spl/spl-vnode.c +++ b/modules/spl/spl-vnode.c @@ -428,7 +428,6 @@ vn_getf(int fd) if (fp) { atomic_inc(&fp->f_ref); spin_unlock(&vn_file_lock); - printk("found file\n"); return fp; } @@ -473,17 +472,13 @@ vn_getf(int fd) return fp; out_vnode: - printk("out_vnode\n"); vn_free(vp); out_fget: - printk("out_fget\n"); fput(lfp); out_mutex: - printk("out_mutex\n"); mutex_exit(&fp->f_lock); kmem_cache_free(vn_file_cache, fp); out: - printk("out\n"); return NULL; } /* getf() */ EXPORT_SYMBOL(getf); @@ -593,17 +588,17 @@ vn_fini(void) rc = kmem_cache_destroy(vn_file_cache); if (rc) - printk("Warning leaked vn_file_cache objects\n"); + printk("spl: Warning leaked vn_file_cache objects\n"); vn_file_cache = NULL; spin_unlock(&vn_file_lock); if (leaked > 0) - printk("Warning: %d files leaked\n", leaked); + printk("spl: Warning %d files leaked\n", leaked); rc = kmem_cache_destroy(vn_cache); if (rc) - printk("Warning leaked vn_cache objects\n"); + printk("spl: Warning leaked vn_cache objects\n"); return; } /* vn_fini() */ diff --git a/modules/splat/splat-internal.h b/modules/splat/splat-internal.h index 61d0fd286..525df5902 100644 --- a/modules/splat/splat-internal.h +++ b/modules/splat/splat-internal.h @@ -38,47 +38,47 @@ #include "splat-ctl.h" #define SPLAT_SUBSYSTEM_INIT(type) \ -({ splat_subsystem_t *_sub_; \ +({ splat_subsystem_t *_sub_; \ \ - _sub_ = (splat_subsystem_t *)splat_##type##_init(); \ + _sub_ = (splat_subsystem_t *)splat_##type##_init(); \ if (_sub_ == NULL) { \ - printk(KERN_ERR "Error initializing: " #type "\n"); \ + printk(KERN_ERR "splat: Error initializing: " #type "\n"); \ } else { \ - spin_lock(&splat_module_lock); \ - list_add_tail(&(_sub_->subsystem_list), \ + spin_lock(&splat_module_lock); \ + list_add_tail(&(_sub_->subsystem_list), \ &splat_module_list); \ - spin_unlock(&splat_module_lock); \ + spin_unlock(&splat_module_lock); \ } \ }) #define SPLAT_SUBSYSTEM_FINI(type) \ -({ splat_subsystem_t *_sub_, *_tmp_; \ +({ splat_subsystem_t *_sub_, *_tmp_; \ int _id_, _flag_ = 0; \ \ - _id_ = splat_##type##_id(); \ - spin_lock(&splat_module_lock); \ + _id_ = splat_##type##_id(); \ + spin_lock(&splat_module_lock); \ list_for_each_entry_safe(_sub_, _tmp_, &splat_module_list, \ subsystem_list) { \ if (_sub_->desc.id == _id_) { \ list_del_init(&(_sub_->subsystem_list)); \ - spin_unlock(&splat_module_lock); \ - splat_##type##_fini(_sub_); \ + spin_unlock(&splat_module_lock); \ + splat_##type##_fini(_sub_); \ spin_lock(&splat_module_lock); \ _flag_ = 1; \ } \ } \ - spin_unlock(&splat_module_lock); \ + spin_unlock(&splat_module_lock); \ \ if (!_flag_) \ - printk(KERN_ERR "Error finalizing: " #type "\n"); \ + printk(KERN_ERR "splat: Error finalizing: " #type "\n"); \ }) #define SPLAT_TEST_INIT(sub, n, d, tid, func) \ -({ splat_test_t *_test_; \ +({ splat_test_t *_test_; \ \ - _test_ = (splat_test_t *)kmalloc(sizeof(*_test_), GFP_KERNEL); \ + _test_ = (splat_test_t *)kmalloc(sizeof(*_test_), GFP_KERNEL); \ if (_test_ == NULL) { \ - printk(KERN_ERR "Error initializing: " n "/" #tid" \n");\ + printk(KERN_ERR "splat: Error initializing: " n "/" #tid" \n");\ } else { \ memset(_test_, 0, sizeof(*_test_)); \ strncpy(_test_->desc.name, n, SPLAT_NAME_SIZE); \ @@ -93,7 +93,7 @@ }) #define SPLAT_TEST_FINI(sub, tid) \ -({ splat_test_t *_test_, *_tmp_; \ +({ splat_test_t *_test_, *_tmp_; \ int _flag_ = 0; \ \ spin_lock(&((sub)->test_lock)); \ @@ -107,7 +107,7 @@ spin_unlock(&((sub)->test_lock)); \ \ if (!_flag_) \ - printk(KERN_ERR "Error finalizing: " #tid "\n"); \ + printk(KERN_ERR "splat: Error finalizing: " #tid "\n"); \ }) typedef int (*splat_test_func_t)(struct file *, void *);