scsi: Implement per-cpu logging buffer

Implement a per-cpu buffer for formatting messages to avoid line breaks
up under high load.  This patch implements scmd_printk() and
sdev_prefix_printk() using the per-cpu buffer and makes sdev_printk() a
wrapper for sdev_prefix_printk().

Tested-by: Robert Elliott <elliott@hp.com>
Reviewed-by: Robert Elliott <elliott@hp.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
Signed-off-by: Christoph Hellwig <hch@lst.de>

3 files changed, 133 insertions, 14 deletions

diff --git a/drivers/scsi/Makefile b/drivers/scsi/Makefile
index 58158f11ed7b..447c2d24aafa 100644
--- a/drivers/scsi/Makefile
+++ b/drivers/scsi/Makefile
@@ -167,7 +167,7 @@ scsi_mod-y			+= scsi_scan.o scsi_sysfs.o scsi_devinfo.o
 scsi_mod-$(CONFIG_SCSI_NETLINK) += scsi_netlink.o
 scsi_mod-$(CONFIG_SYSCTL)       += scsi_sysctl.o
 scsi_mod-$(CONFIG_SCSI_PROC_FS) += scsi_proc.o
-scsi_mod-y                      += scsi_trace.o
+scsi_mod-y                      += scsi_trace.o scsi_logging.o
 scsi_mod-$(CONFIG_PM)           += scsi_pm.o
 
 hv_storvsc-y                    := storvsc_drv.o
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c
new file mode 100644
index 000000000000..09d65dea9d56
--- /dev/null
+++ b/drivers/scsi/scsi_logging.c
@@ -0,0 +1,124 @@
+/*
+ * scsi_logging.c
+ *
+ * Copyright (C) 2014 SUSE Linux Products GmbH
+ * Copyright (C) 2014 Hannes Reinecke <hare@suse.de>
+ *
+ * This file is released under the GPLv2
+ */
+
+#include <linux/kernel.h>
+#include <linux/atomic.h>
+
+#include <scsi/scsi.h>
+#include <scsi/scsi_cmnd.h>
+#include <scsi/scsi_device.h>
+#include <scsi/scsi_dbg.h>
+
+#define SCSI_LOG_SPOOLSIZE 4096
+#define SCSI_LOG_BUFSIZE 128
+
+#if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG
+#warning SCSI logging bitmask too large
+#endif
+
+struct scsi_log_buf {
+        char buffer[SCSI_LOG_SPOOLSIZE];
+        unsigned long map;
+};
+
+static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log);
+
+static char *scsi_log_reserve_buffer(size_t *len)
+{
+        struct scsi_log_buf *buf;
+        unsigned long map_bits = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE;
+        unsigned long idx = 0;
+
+        preempt_disable();
+        buf = this_cpu_ptr(&scsi_format_log);
+        idx = find_first_zero_bit(&buf->map, map_bits);
+        if (likely(idx < map_bits)) {
+                while (test_and_set_bit(idx, &buf->map)) {
+                        idx = find_next_zero_bit(&buf->map, map_bits, idx);
+                        if (idx >= map_bits)
+                                break;
+                }
+        }
+        if (WARN_ON(idx >= map_bits)) {
+                preempt_enable();
+                return NULL;
+        }
+        *len = SCSI_LOG_BUFSIZE;
+        return buf->buffer + idx * SCSI_LOG_BUFSIZE;
+}
+
+static void scsi_log_release_buffer(char *bufptr)
+{
+        struct scsi_log_buf *buf;
+        unsigned long idx;
+        int ret;
+
+        buf = this_cpu_ptr(&scsi_format_log);
+        if (bufptr >= buf->buffer &&
+            bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) {
+                idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE;
+                ret = test_and_clear_bit(idx, &buf->map);
+                WARN_ON(!ret);
+        }
+        preempt_enable();
+}
+
+int sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
+                       const char *name, const char *fmt, ...)
+{
+        va_list args;
+        char *logbuf;
+        size_t off = 0, logbuf_len;
+        int ret;
+
+        if (!sdev)
+                return 0;
+
+        logbuf = scsi_log_reserve_buffer(&logbuf_len);
+        if (!logbuf)
+                return 0;
+
+        if (name)
+                off += scnprintf(logbuf + off, logbuf_len - off,
+                                 "[%s] ", name);
+        va_start(args, fmt);
+        off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
+        va_end(args);
+        ret = dev_printk(level, &sdev->sdev_gendev, "%s", logbuf);
+        scsi_log_release_buffer(logbuf);
+        return ret;
+}
+EXPORT_SYMBOL(sdev_prefix_printk);
+
+int scmd_printk(const char *level, const struct scsi_cmnd *scmd,
+                const char *fmt, ...)
+{
+        struct gendisk *disk = scmd->request->rq_disk;
+        va_list args;
+        char *logbuf;
+        size_t off = 0, logbuf_len;
+        int ret;
+
+        if (!scmd || !scmd->cmnd)
+                return 0;
+
+        logbuf = scsi_log_reserve_buffer(&logbuf_len);
+        if (!logbuf)
+                return 0;
+        if (disk)
+                off += scnprintf(logbuf + off, logbuf_len - off,
+                                 "[%s] ", disk->disk_name);
+        va_start(args, fmt);
+        off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
+        va_end(args);
+        ret = dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf);
+        scsi_log_release_buffer(logbuf);
+        return ret;
+}
+EXPORT_SYMBOL(scmd_printk);
diff --git a/include/scsi/scsi_device.h b/include/scsi/scsi_device.h
index 3a4edd1f7dbb..d1aad4d04334 100644
--- a/include/scsi/scsi_device.h
+++ b/include/scsi/scsi_device.h
@@ -230,9 +230,6 @@ struct scsi_dh_data {
 #define transport_class_to_sdev(class_dev) \
         to_scsi_device(class_dev->parent)
 
-#define sdev_printk(prefix, sdev, fmt, a...)    \
-        dev_printk(prefix, &(sdev)->sdev_gendev, fmt, ##a)
-
 #define sdev_dbg(sdev, fmt, a...) \
         dev_dbg(&(sdev)->sdev_gendev, fmt, ##a)
 
@@ -240,16 +237,14 @@ struct scsi_dh_data {
  * like scmd_printk, but the device name is passed in
  * as a string pointer
  */
-#define sdev_prefix_printk(l, sdev, p, fmt, a...)                       \
-        (p) ?                                                           \
-        sdev_printk(l, sdev, "[%s] " fmt, p, ##a) :                     \
-        sdev_printk(l, sdev, fmt, ##a)
-
-#define scmd_printk(prefix, scmd, fmt, a...)                            \
-        (scmd)->request->rq_disk ?                                      \
-        sdev_printk(prefix, (scmd)->device, "[%s] " fmt,                \
-                    (scmd)->request->rq_disk->disk_name, ##a) :         \
-        sdev_printk(prefix, (scmd)->device, fmt, ##a)
+extern int sdev_prefix_printk(const char *, const struct scsi_device *,
+                              const char *, const char *, ...);
+
+#define sdev_printk(l, sdev, fmt, a...)                         \
+        sdev_prefix_printk(l, sdev, NULL, fmt, ##a)
+
+extern int scmd_printk(const char *, const struct scsi_cmnd *,
+                       const char *, ...);
 
 #define scmd_dbg(scmd, fmt, a...)                                          \
         do {                                                               \