[PATCH][RFC 4/23]: SCST debug support

Vladislav Bolkhovitin
2008-12-10T18:36:39Z

This patch contains definitions and functions for tracing various
internal events. It can be fully compiled out and have no runtime overhead.

Signed-off-by: Vladislav Bolkhovitin <vst@vlnb.net>
---
drivers/scst/scst_debug.c | 128 ++++++++++++++++
include/scst/scst_debug.h | 361 ++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 489 insertions(+)

diff -uprN orig/linux-2.6.27/include/scst/scst_debug.h linux-2.6.27/include/scst/scst_debug.h
--- orig/linux-2.6.27/include/scst/scst_debug.h
+++ linux-2.6.27/include/scst/scst_debug.h
@@ -0,0 +1,361 @@
+/*
+ * include/scst_debug.h
+ *
+ * Copyright (C) 2004 - 2008 Vladislav Bolkhovitin <vst@vlnb.net>
+ * Copyright (C) 2004 - 2005 Leonid Stoljar
+ * Copyright (C) 2007 - 2008 CMS Distribution Limited
+ *
+ * Contains macroses for execution tracing and error reporting
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License
+ * as published by the Free Software Foundation, version 2
+ * of the License.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ */
+
+#ifndef __SCST_DEBUG_H
+#define __SCST_DEBUG_H
+
+#include <linux/autoconf.h> /* for CONFIG_* */
+
+#include <linux/bug.h> /* for WARN_ON_ONCE */
+
+
+
+#ifdef CONFIG_SCST_EXTRACHECKS
+#define EXTRACHECKS_BUG_ON(a) BUG_ON(a)
+#define EXTRACHECKS_WARN_ON(a) WARN_ON(a)
+#define EXTRACHECKS_WARN_ON_ONCE(a) WARN_ON_ONCE(a)
+#else
+#define EXTRACHECKS_BUG_ON(a)
+#define EXTRACHECKS_WARN_ON(a)
+#define EXTRACHECKS_WARN_ON_ONCE(a)
+#endif
+
+#ifdef CONFIG_SCST_DEBUG
+/*# define LOG_FLAG KERN_DEBUG*/
+# define LOG_FLAG KERN_INFO
+# define INFO_FLAG KERN_INFO
+# define ERROR_FLAG KERN_INFO
+#else
+# define LOG_FLAG KERN_INFO
+# define INFO_FLAG KERN_INFO
+# define ERROR_FLAG KERN_ERR
+#endif
+
+#define CRIT_FLAG KERN_CRIT
+
+#define NO_FLAG ""
+
+#define TRACE_NULL 0x00000000
+#define TRACE_DEBUG 0x00000001
+#define TRACE_FUNCTION 0x00000002
+#define TRACE_LINE 0x00000004
+#define TRACE_PID 0x00000008
+#define TRACE_ENTRYEXIT 0x00000010
+#define TRACE_BUFF 0x00000020
+#define TRACE_MEMORY 0x00000040
+#define TRACE_SG_OP 0x00000080
+#define TRACE_OUT_OF_MEM 0x00000100
+#define TRACE_MINOR 0x00000200 /* less important events */
+#define TRACE_MGMT 0x00000400
+#define TRACE_MGMT_MINOR 0x00000800
+#define TRACE_MGMT_DEBUG 0x00001000
+#define TRACE_SCSI 0x00002000
+#define TRACE_SPECIAL 0x00004000 /* filtering debug, etc */
+#define TRACE_ALL 0xffffffff
+/* Flags 0xXXXX0000 are local for users */
+
+/*
+ * Note: in the next two printk() statements the KERN_CONT macro is only
+ * present to suppress a checkpatch warning (KERN_CONT is defined as "").
+ */
+#define PRINT(log_flag, format, args...) \
+ printk(KERN_CONT "%s" format "\n", log_flag, ## args)
+#define PRINTN(log_flag, format, args...) \
+ printk(KERN_CONT "%s" format, log_flag, ## args)
+
+#ifdef LOG_PREFIX
+#define __LOG_PREFIX LOG_PREFIX
+#else
+#define __LOG_PREFIX NULL
+#endif
+
+#if defined(CONFIG_SCST_DEBUG) || defined(CONFIG_SCST_TRACING)
+
+#ifndef CONFIG_SCST_DEBUG
+#define ___unlikely(a) (a)
+#else
+#define ___unlikely(a) unlikely(a)
+#endif
+
+extern int debug_print_prefix(unsigned long trace_flag, const char *log_level,
+ const char *prefix, const char *func, int line);
+extern void debug_print_buffer(const char *log_level, const void *data,
+ int len);
+
+#define TRACE(trace, format, args...) \
+do { \
+ if (___unlikely(trace_flag & (trace))) { \
+ char *__tflag = LOG_FLAG; \
+ if (debug_print_prefix(trace_flag, __tflag, __LOG_PREFIX, \
+ __func__, __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s" format, __tflag, args); \
+ } \
+} while (0)
+
+#define PRINT_BUFFER(message, buff, len) \
+do { \
+ PRINT(NO_FLAG, "%s:", message); \
+ debug_print_buffer(INFO_FLAG, buff, len); \
+} while (0)
+
+#define PRINT_BUFF_FLAG(flag, message, buff, len) \
+do { \
+ if (___unlikely(trace_flag & (flag))) { \
+ char *__tflag = INFO_FLAG; \
+ if (debug_print_prefix(trace_flag, __tflag, NULL, __func__,\
+ __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s%s:", __tflag, message); \
+ debug_print_buffer(INFO_FLAG, buff, len); \
+ } \
+} while (0)
+
+#else /* CONFIG_SCST_DEBUG || CONFIG_SCST_TRACING */
+
+#define TRACE(trace, args...) do {} while (0)
+#define PRINT_BUFFER(message, buff, len) do {} while (0)
+#define PRINT_BUFF_FLAG(flag, message, buff, len) do {} while (0)
+
+#endif /* CONFIG_SCST_DEBUG || CONFIG_SCST_TRACING */
+
+#ifdef CONFIG_SCST_DEBUG
+
+#define __TRACE(trace, format, args...) \
+do { \
+ if (trace_flag & (trace)) { \
+ char *__tflag = LOG_FLAG; \
+ if (debug_print_prefix(trace_flag, __tflag, NULL, __func__,\
+ __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s" format, __tflag, args); \
+ } \
+} while (0)
+
+#define TRACE_MEM(args...) __TRACE(TRACE_MEMORY, args)
+#define TRACE_SG(args...) __TRACE(TRACE_SG_OP, args)
+#define TRACE_DBG(args...) __TRACE(TRACE_DEBUG, args)
+#define TRACE_DBG_SPECIAL(args...) __TRACE(TRACE_DEBUG|TRACE_SPECIAL, args)
+#define TRACE_MGMT_DBG(args...) __TRACE(TRACE_MGMT_DEBUG, args)
+#define TRACE_MGMT_DBG_SPECIAL(args...) \
+ __TRACE(TRACE_MGMT_DEBUG|TRACE_SPECIAL, args)
+
+#define TRACE_BUFFER(message, buff, len) \
+do { \
+ if (trace_flag & TRACE_BUFF) { \
+ char *__tflag = LOG_FLAG; \
+ if (debug_print_prefix(trace_flag, __tflag, NULL, __func__, \
+ __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s%s:", __tflag, message); \
+ debug_print_buffer(LOG_FLAG, buff, len); \
+ } \
+} while (0)
+
+#define TRACE_BUFF_FLAG(flag, message, buff, len) \
+do { \
+ if (trace_flag & (flag)) { \
+ char *__tflag = LOG_FLAG; \
+ if (debug_print_prefix(trace_flag, __tflag, NULL, __func__, \
+ __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s%s:", __tflag, message); \
+ debug_print_buffer(LOG_FLAG, buff, len); \
+ } \
+} while (0)
+
+#define PRINT_LOG_FLAG(log_flag, format, args...) \
+do { \
+ char *__tflag = log_flag; \
+ if (debug_print_prefix(trace_flag, __tflag, __LOG_PREFIX, \
+ __func__, __LINE__) > 0) { \
+ __tflag = NO_FLAG; \
+ } \
+ PRINT(NO_FLAG, "%s" format, __tflag, args); \
+} while (0)
+
+#define PRINT_WARNING(format, args...) \
+do { \
+ if (strcmp(INFO_FLAG, LOG_FLAG)) { \
+ PRINT_LOG_FLAG(LOG_FLAG, "***WARNING*** " format, args); \
+ } \
+ PRINT_LOG_FLAG(INFO_FLAG, "***WARNING*** " format, args); \
+} while (0)
+
+#define PRINT_ERROR(format, args...) \
+do { \
+ if (strcmp(ERROR_FLAG, LOG_FLAG)) { \
+ PRINT_LOG_FLAG(LOG_FLAG, "***ERROR*** " format, args); \
+ } \
+ PRINT_LOG_FLAG(ERROR_FLAG, "***ERROR*** " format, args); \
+} while (0)
+
+#define PRINT_CRIT_ERROR(format, args...) \
+do { \
+ /* if (strcmp(CRIT_FLAG, LOG_FLAG)) \
+ { \
+ PRINT_LOG_FLAG(LOG_FLAG, "***CRITICAL ERROR*** " format, args); \
+ }*/ \
+ PRINT_LOG_FLAG(CRIT_FLAG, "***CRITICAL ERROR*** " format, args); \
+} while (0)
+
+#define PRINT_INFO(format, args...) \
+do { \
+ if (strcmp(INFO_FLAG, LOG_FLAG)) { \
+ PRINT_LOG_FLAG(LOG_FLAG, format, args); \
+ } \
+ PRINT_LOG_FLAG(INFO_FLAG, format, args); \
+} while (0)
+
+#define TRACE_ENTRY() \
+do { \
+ if (trace_flag & TRACE_ENTRYEXIT) { \
+ if (trace_flag & TRACE_PID) { \
+ PRINT(LOG_FLAG, "[%d]: ENTRY %s", current->pid, \
+ __func__); \
+ } \
+ else { \
+ PRINT(LOG_FLAG, "ENTRY %s", __func__); \
+ } \
+ } \
+} while (0)
+
+#define TRACE_EXIT() \
+do { \
+ if (trace_flag & TRACE_ENTRYEXIT) { \
+ if (trace_flag & TRACE_PID) { \
+ PRINT(LOG_FLAG, "[%d]: EXIT %s", current->pid, \
+ __func__); \
+ } \
+ else { \
+ PRINT(LOG_FLAG, "EXIT %s", __func__); \
+ } \
+ } \
+} while (0)
+
+#define TRACE_EXIT_RES(res) \
+do { \
+ if (trace_flag & TRACE_ENTRYEXIT) { \
+ if (trace_flag & TRACE_PID) { \
+ PRINT(LOG_FLAG, "[%d]: EXIT %s: %ld", current->pid, \
+ __func__, (long)(res)); \
+ } \
+ else { \
+ PRINT(LOG_FLAG, "EXIT %s: %ld", \
+ __func__, (long)(res)); \
+ } \
+ } \
+} while (0)
+
+#define TRACE_EXIT_HRES(res) \
+do { \
+ if (trace_flag & TRACE_ENTRYEXIT) { \
+ if (trace_flag & TRACE_PID) { \
+ PRINT(LOG_FLAG, "[%d]: EXIT %s: 0x%lx", current->pid, \
+ __func__, (long)(res)); \
+ } \
+ else { \
+ PRINT(LOG_FLAG, "EXIT %s: %lx", \
+ __func__, (long)(res)); \
+ } \
+ } \
+} while (0)
+
+#else /* CONFIG_SCST_DEBUG */
+
+#define TRACE_MEM(format, args...) do {} while (0)
+#define TRACE_SG(format, args...) do {} while (0)
+#define TRACE_DBG(format, args...) do {} while (0)
+#define TRACE_DBG_SPECIAL(format, args...) do {} while (0)
+#define TRACE_MGMT_DBG(format, args...) do {} while (0)
+#define TRACE_MGMT_DBG_SPECIAL(format, args...) do {} while (0)
+#define TRACE_BUFFER(message, buff, len) do {} while (0)
+#define TRACE_BUFF_FLAG(flag, message, buff, len) do {} while (0)
+#define TRACE_ENTRY() do {} while (0)
+#define TRACE_EXIT() do {} while (0)
+#define TRACE_EXIT_RES(res) do {} while (0)
+#define TRACE_EXIT_HRES(res) do {} while (0)
+
+#ifdef LOG_PREFIX
+
+#define PRINT_INFO(format, args...) \
+do { \
+ PRINT(INFO_FLAG, "%s: " format, LOG_PREFIX, args); \
+} while (0)
+
+#define PRINT_WARNING(format, args...) \
+do { \
+ PRINT(INFO_FLAG, "%s: ***WARNING*** " \
+ format, LOG_PREFIX, args); \
+} while (0)
+
+#define PRINT_ERROR(format, args...) \
+do { \
+ PRINT(ERROR_FLAG, "%s: ***ERROR*** " \
+ format, LOG_PREFIX, args); \
+} while (0)
+
+#define PRINT_CRIT_ERROR(format, args...) \
+do { \
+ PRINT(CRIT_FLAG, "%s: ***CRITICAL ERROR*** " \
+ format, LOG_PREFIX, args); \
+} while (0)
+
+#else
+
+#define PRINT_INFO(format, args...) \
+do { \
+ PRINT(INFO_FLAG, format, args); \
+} while (0)
+
+#define PRINT_WARNING(format, args...) \
+do { \
+ PRINT(INFO_FLAG, "***WARNING*** " \
+ format, args); \
+} while (0)
+
+#define PRINT_ERROR(format, args...) \
+do { \
+ PRINT(ERROR_FLAG, "***ERROR*** " \
+ format, args); \
+} while (0)
+
+#define PRINT_CRIT_ERROR(format, args...) \
+do { \
+ PRINT(CRIT_FLAG, "***CRITICAL ERROR*** " \
+ format, args); \
+} while (0)
+
+#endif /* LOG_PREFIX */
+
+#endif /* CONFIG_SCST_DEBUG */
+
+#if defined(CONFIG_SCST_DEBUG) && defined(CONFIG_DEBUG_SLAB)
+#define SCST_SLAB_FLAGS (SLAB_RED_ZONE | SLAB_POISON)
+#else
+#define SCST_SLAB_FLAGS 0L
+#endif
+
+#endif /* __SCST_DEBUG_H */
diff -uprN orig/linux-2.6.27/drivers/scst/scst_debug.c linux-2.6.27/drivers/scst/scst_debug.c
--- orig/linux-2.6.27/drivers/scst/scst_debug.c
+++ linux-2.6.27/drivers/scst/scst_debug.c
@@ -0,0 +1,128 @@
+/*
+ * scst_debug.c
+ *
+ * Copyright (C) 2004 - 2008 Vladislav Bolkhovitin <vst@vlnb.net>
+ * Copyright (C) 2004 - 2005 Leonid Stoljar
+ * Copyright (C) 2007 - 2008 CMS Distribution Limited
+ *
+ * Contains helper functions for execution tracing and error reporting.
+ * Intended to be included in main .c file.
+ *
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU General Public License
+ * as published by the Free Software Foundation, version 2
+ * of the License.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ */
+
+#include "scst.h"
+#include "scst_debug.h"
+
+#if defined(CONFIG_SCST_DEBUG) || defined(CONFIG_SCST_TRACING)
+
+#define TRACE_BUF_SIZE 512
+
+static char trace_buf[TRACE_BUF_SIZE];
+static DEFINE_SPINLOCK(trace_buf_lock);
+
+static inline int get_current_tid(void)
+{
+ /* Code should be the same as in sys_gettid() */
+ if (in_interrupt()) {
+ /*
+ * Unfortunately, task_pid_vnr() isn't IRQ-safe, so otherwise
+ * it can oops. ToDo.
+ */
+ return 0;
+ }
+ return task_pid_vnr(current);
+}
+
+int debug_print_prefix(unsigned long trace_flag, const char *log_level,
+ const char *prefix, const char *func, int line)
+{
+ int i = 0;
+ unsigned long flags;
+
+ spin_lock_irqsave(&trace_buf_lock, flags);
+
+ if (trace_flag & TRACE_PID)
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE, "[%d]: ",
+ get_current_tid());
+ if (prefix != NULL)
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i, "%s: ",
+ prefix);
+ if (trace_flag & TRACE_FUNCTION)
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i, "%s:", func);
+ if (trace_flag & TRACE_LINE)
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i, "%i:", line);
+
+ if (i > 0)
+ PRINTN(log_level, "%s", trace_buf);
+
+ spin_unlock_irqrestore(&trace_buf_lock, flags);
+
+ return i;
+}
+EXPORT_SYMBOL(debug_print_prefix);
+
+void debug_print_buffer(const char *log_level, const void *data, int len)
+{
+ int z, z1, i;
+ const unsigned char *buf = (const unsigned char *) data;
+ int f = 0;
+ unsigned long flags;
+
+ if (buf == NULL)
+ return;
+
+ spin_lock_irqsave(&trace_buf_lock, flags);
+
+ PRINT(NO_FLAG, " (h)___0__1__2__3__4__5__6__7__8__9__A__B__C__D__E__F");
+ for (z = 0, z1 = 0, i = 0; z < len; z++) {
+ if (z % 16 == 0) {
+ if (z != 0) {
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i,
+ " ");
+ for (; (z1 < z) && (i < TRACE_BUF_SIZE - 1);
+ z1++) {
+ if ((buf[z1] >= 0x20) &&
+ (buf[z1] < 0x80))
+ trace_buf[i++] = buf[z1];
+ else
+ trace_buf[i++] = '.';
+ }
+ trace_buf[i] = '\0';
+ PRINT(NO_FLAG, "%s", trace_buf);
+ i = 0;
+ f = 1;
+ }
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i,
+ "%4x: ", z);
+ }
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i, "%02x ",
+ buf[z]);
+ }
+ i += snprintf(&trace_buf[i], TRACE_BUF_SIZE - i, " ");
+ for (; (z1 < z) && (i < TRACE_BUF_SIZE - 1); z1++) {
+ if ((buf[z1] > 0x20) && (buf[z1] < 0x80))
+ trace_buf[i++] = buf[z1];
+ else
+ trace_buf[i++] = '.';
+ }
+ trace_buf[i] = '\0';
+ if (f)
+ PRINT(log_level, "%s", trace_buf);
+ else
+ PRINT(NO_FLAG, "%s", trace_buf);
+
+ spin_unlock_irqrestore(&trace_buf_lock, flags);
+ return;
+}
+EXPORT_SYMBOL(debug_print_buffer);
+
+#endif /* CONFIG_SCST_DEBUG || CONFIG_SCST_TRACING */