* [PATCH 3/5] printk: implement merging printk
2008-01-21 5:13 [PATCHSET] printk: implement printk_header() and merging printk, take #2 Tejun Heo
2008-01-21 5:13 ` [PATCH 1/5] printk: keep log level on multiline messages Tejun Heo
2008-01-21 5:13 ` [PATCH 2/5] printk: implement [v]printk_header() Tejun Heo
@ 2008-01-21 5:13 ` Tejun Heo
2008-01-21 5:13 ` [PATCH 4/5] printk: add Documentation/printk.txt Tejun Heo
` (2 subsequent siblings)
5 siblings, 0 replies; 12+ messages in thread
From: Tejun Heo @ 2008-01-21 5:13 UTC (permalink / raw)
To: randy.dunlap, daniel.ritz-ml, matthew, jeff, linux-kernel,
linux-ide
Cc: Tejun Heo
There often are times printk messages need to be assembled piece by
piece and it's usually done using one of the following methods.
* Calling printk() on partial message segments. This used to be quite
common but has a problem - the message can break up if someone else
prints something in the middle.
* Prepping a temp buffer and build message piece-by-piece using
snprintf(). This is the most generic solution but corner case
handling can be tedious and on overflow messages can be lost and
such overflows would go unnoticed if overflow detection isn't
properly done.
* Collect all the partial data and perform printk() once with all the
parameters. This is often combined with the second. This usually
works but printing messages can become non-trivial programming
problem and can get quite tedious if the message format varies
depending on data.
None of the above is quite satisfactory. This patch implement merging
printk - mprintk to deal with this problem. It's basically a helper
to construct message piece-by-piece into the specified buffer. The
caller still has to care about buffer size and how the buffer is
allocated but mprintk makes it easier.
* DEFINE_MPRINTK() macro makes it easy to define a mprintk instance
with on-stack buffer. Malloc'd buffer can also be used.
* Message is never lost. On buffer overflow, all queued and to be
queued messages are printed followed by warning message and stack
dump. The warning message and stack dump are printed only once per
mprintk instance. The caller also doesn't have to handle buffer
malloc failure. If buffer is initialized to NULL, mprintk simply
bypasses the messages to printk().
* Has good support for multiline messages. A mprintk instance can
have header associated with it and the header can have log level.
Header log level is used if a partial message doesn't specify log
level explicitly. When log level is specified explicitly in a
partial message, the log level is applied to the partial message
only.
A simple example.
DEFINE_MPRINTK(mp, 2 * 80);
mprintk_set_header(&mp, KERN_DEBUG "ata%u.%2u: ", 1, 0);
mprintk_push(&mp, "ATA %d", 7);
mprintk_push(&mp, ", %u sectors\n", 1024);
mprintk(&mp, "everything seems dandy\n");
Which will be printed like the following as a single message.
<7>ata1.00: ATA 7, 1024 sectors
<7> everything seems dandy
Signed-off-by: Tejun Heo <htejun@gmail.com>
---
include/linux/kernel.h | 69 +++++++++++++
kernel/printk.c | 253 ++++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 322 insertions(+), 0 deletions(-)
diff --git a/include/linux/kernel.h b/include/linux/kernel.h
index ade3ac9..4bf325d 100644
--- a/include/linux/kernel.h
+++ b/include/linux/kernel.h
@@ -175,6 +175,27 @@ extern struct pid *session_of_pgrp(struct pid *pgrp);
extern void dump_thread(struct pt_regs *regs, struct user *dump);
#ifdef CONFIG_PRINTK
+struct mprintk {
+ char *buf;
+ char *body;
+ char *cur;
+ char *end;
+ unsigned int flags;
+};
+
+#define MPRINTK_INITIALIZER(_buf, _size) \
+ { \
+ .buf = _buf, \
+ .body = _buf, \
+ .cur = _buf, \
+ .end = _buf + _size, \
+ .flags = 0 \
+ }
+
+#define DEFINE_MPRINTK(name, size) \
+ char __##name##_buf[size]; \
+ struct mprintk name = MPRINTK_INITIALIZER(__##name##_buf, size)
+
asmlinkage int vprintk_header(const char *header, const char *fmt, va_list args)
__attribute__ ((format (printf, 2, 0)));
asmlinkage int printk_header(const char *header, const char * fmt, ...)
@@ -183,10 +204,33 @@ asmlinkage int vprintk(const char *fmt, va_list args)
__attribute__ ((format (printf, 1, 0)));
asmlinkage int printk(const char * fmt, ...)
__attribute__ ((format (printf, 1, 2))) __cold;
+
+static inline void mprintk_init(struct mprintk *mp, char *buf, size_t size)
+{
+ *mp = (struct mprintk)MPRINTK_INITIALIZER(buf, size);
+}
+extern int vmprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+extern int vmprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+extern int vmprintk(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+extern int mprintk_add(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+extern int mprintk_set_header(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+extern int mprintk(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+
extern int log_buf_get_len(void);
extern int log_buf_read(int idx);
extern int log_buf_copy(char *dest, int idx, int len);
#else
+struct mprintk { };
+#define MPRINTK_INITIALIZER(_buf, _size) { }
+#define DEFINE_MPRINTK(name, size) \
+ struct mprintk name = __MPRINTK_INITIALIZER(NULL, size)
+
static inline int vprintk_header(const char *header, const char *s, va_list args)
__attribute__ ((format (printf, 2, 0)));
static inline int vprintk_header(const char *header, const char *s, va_list args)
@@ -201,6 +245,31 @@ static inline int vprintk(const char *s, va_list args) { return 0; }
static inline int printk(const char *s, ...)
__attribute__ ((format (printf, 1, 2)));
static inline int __cold printk(const char *s, ...) { return 0; }
+static inline void mprintk_init(struct mprintk *mp, char *buf, size_t size) { }
+static inline int vmprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+static inline int vmprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+{ return 0; }
+static inline int vmprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+static inline int vmprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+{ return 0; }
+static inline int vmprintk(struct mprintk *mp, const char *fmt, va_list args)
+ __attribute__ ((format (printf, 2, 0)));
+static inline int vmprintk(struct mprintk *mp, const char *fmt, va_list args)
+{ return 0; }
+static inline int mprintk_add(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+static inline int mprintk_add(struct mprintk *mp, const char *fmt, ...)
+{ return 0; }
+static inline int mprintk_set_header(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+static inline int mprintk_set_header(struct mprintk *mp, const char *fmt, ...)
+{ return 0; }
+static inline int mprintk(struct mprintk *mp, const char *fmt, ...)
+ __attribute__ ((format (printf, 2, 3)));
+static inline int mprintk(struct mprintk *mp, const char *fmt, ...)
+{ return 0; }
static inline int log_buf_get_len(void) { return 0; }
static inline int log_buf_read(int idx) { return 0; }
static inline int log_buf_copy(char *dest, int idx, int len) { return 0; }
diff --git a/kernel/printk.c b/kernel/printk.c
index 1cde1d6..f9683c6 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -45,6 +45,11 @@
#define MINIMUM_CONSOLE_LOGLEVEL 1 /* Minimum loglevel we let people use */
#define DEFAULT_CONSOLE_LOGLEVEL 7 /* anything MORE serious than KERN_DEBUG */
+/* mprintk flags */
+#define MPRINTK_HAS_HEADER_LOGLV (1 << 0)
+#define MPRINTK_OVERFLOWED (1 << 1)
+#define MPRINTK_LOGLV_OVERRIDDEN (1 << 2)
+
DECLARE_WAIT_QUEUE_HEAD(log_wait);
int console_printk[4] = {
@@ -832,6 +837,254 @@ asmlinkage int vprintk_header(const char *header, const char *fmt, va_list args)
}
EXPORT_SYMBOL(vprintk_header);
+static bool mp_no_buffer(struct mprintk *mp)
+{
+ return unlikely(!mp->cur || mp->buf == mp->end);
+}
+
+static char *mp_header(struct mprintk *mp)
+{
+ if (mp->body != mp->buf)
+ return mp->buf;
+ return NULL;
+}
+
+static void mp_flush(struct mprintk *mp)
+{
+ printk_header(mp_header(mp), "%s", mp->body);
+ mp->cur = mp->body;
+ mp->cur[0] = '\0';
+ mp->flags &= ~MPRINTK_LOGLV_OVERRIDDEN;
+}
+
+/**
+ * vmprintk_add - format and add message chunk to merging printk instance
+ * @mp: mprintk instance to use
+ * @fmt: format string
+ * @args: va_list to format @fmt
+ *
+ * This function is identical to mprintk_add() except that it takes
+ * va_list @args intead of argument list.
+ */
+int vmprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+{
+ char *start = mp->cur;
+ size_t size = mp->end - start;
+ int new_line = mp->cur == mp->body || mp->cur[-1] == '\n';
+ int printed = 0;
+ int ret;
+
+ if (mp_no_buffer(mp))
+ return vprintk(fmt, args);
+
+ /*
+ * Prepend header log level if the previous chunk has
+ * overridden the log level (implies header log level exists)
+ * && the current chunk starts a new line and doesn't have
+ * explicit log level.
+ */
+ if ((mp->flags & MPRINTK_LOGLV_OVERRIDDEN) && new_line) {
+ char tbuf[4];
+ va_list args_copy;
+
+ va_copy(args_copy, args);
+ vsnprintf(tbuf, sizeof(tbuf), fmt, args_copy);
+ va_end(args_copy);
+
+ if (!is_loglevel(tbuf)) {
+ ret = snprintf(start, size, "<%c>", mp_header(mp)[1]);
+ printed += ret;
+ if (ret >= size)
+ goto overflow;
+ start += ret;
+ size -= ret;
+ mp->flags &= ~MPRINTK_LOGLV_OVERRIDDEN;
+ }
+ }
+
+ ret = vsnprintf(start, size, fmt, args);
+ printed += ret;
+ if (ret >= size)
+ goto overflow;
+
+ if ((mp->flags & MPRINTK_HAS_HEADER_LOGLV) &&
+ new_line && is_loglevel(start))
+ mp->flags |= MPRINTK_LOGLV_OVERRIDDEN;
+
+ mp->cur += printed;
+
+ return printed;
+
+ overflow:
+ mp->cur[0] = '\0';
+ mp_flush(mp);
+ printed = vprintk_header(mp_header(mp), fmt, args);
+
+ if (!(mp->flags & MPRINTK_OVERFLOWED)) {
+ printk("\n" KERN_ERR
+ "mprintk buffer overflow, please file a bug report\n");
+ dump_stack();
+ mp->flags |= MPRINTK_OVERFLOWED;
+ }
+
+ return printed;
+}
+EXPORT_SYMBOL(vmprintk_add);
+
+/**
+ * vmprintk_set_header - format and set header to merging printk instance
+ * @mp: mprintk instance to use
+ * @fmt: format string
+ * @args: va_list to format @fmt
+ *
+ * This function is identical to mprintk_set_header() except that it
+ * takes va_list @args intead of argument list.
+ */
+int vmprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+{
+ const char *reason;
+ int ret;
+
+ if (mp_no_buffer(mp))
+ return vprintk(fmt, args);
+
+ if (mp_header(mp) || mp->cur != mp->body) {
+ reason = "dirty mprintk instance";
+ goto err;
+ }
+ if (mp->body + 1 == mp->end) {
+ reason = "buffer too short (1 byte)";
+ goto err;
+ }
+
+ /* reserve one byte for separator */
+ mp->end--;
+ ret = vmprintk_add(mp, fmt, args);
+ mp->end++;
+
+ if (mp->cur != mp->body) {
+ mp->body = ++mp->cur;
+ if (is_loglevel(mp_header(mp)))
+ mp->flags |= MPRINTK_HAS_HEADER_LOGLV;
+ }
+
+ return ret;
+
+ err:
+ printk(KERN_WARNING "vmprintk_set_header() failed: %s\n", reason);
+ dump_stack();
+ return 0;
+}
+EXPORT_SYMBOL(vmprintk_set_header);
+
+/**
+ * vmprintk - format and add message chunk to merging printk instance and flush
+ * @mp: mprintk instance to use
+ * @fmt: format string
+ * @args: va_list to format @fmt
+ *
+ * This function is identical to mprintk() except that it takes
+ * va_list @args intead of argument list.
+ */
+int vmprintk(struct mprintk *mp, const char *fmt, va_list args)
+{
+ int ret = 0;
+
+ if (mp_no_buffer(mp))
+ return vprintk(fmt, args);
+
+ if (fmt)
+ ret = vmprintk_add(mp, fmt, args);
+ mp_flush(mp);
+
+ return ret;
+}
+EXPORT_SYMBOL(vmprintk);
+
+/**
+ * mprintk_add - format and add message chunk to merging printk instance
+ * @mp: mprintk instance to use
+ * @fmt: format string
+ *
+ * This function formats @fmt and the following list of arguments and
+ * append the result to @mp. If @mp has header with log level and
+ * @fmt is multiline, this function takes care of restoring header log
+ * level if the previous message contained log level overrided and
+ * this message doesn't.
+ *
+ * If the buffer pointed to by @mp is too short to contain the added
+ * message, @mp is flushed, the message to add is printed directly and
+ * warning message with stack dump is printed. If buffer is NULL, the
+ * formatted message is printed directly. Message is never lost. The
+ * warning message and the stack dump are printed only once for each
+ * @mp instance.
+ *
+ * For example, if @mp header is set to "<7>ata1.00: " and the first
+ * message is "line0\n", second "<4>line1\nline2\n" and the third
+ * "line3\n", the following is the end result.
+ *
+ * <7>ata1.00: line0
+ * <4>ata1.00: line1 (different log level, header is printed again)
+ * <4> line2
+ * <7> line3
+ */
+int mprintk_add(struct mprintk *mp, const char *fmt, ...)
+{
+ va_list args;
+ int ret;
+
+ va_start(args, fmt);
+ ret = vmprintk_add(mp, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+EXPORT_SYMBOL(mprintk_add);
+
+/**
+ * mprintk_set_header - set header of merging printk instance
+ * @mp: mprintk instance to use
+ * @fmt: format string
+ *
+ * Set header of @mp to the string formatted according to @fmt and
+ * arguments.
+ */
+int mprintk_set_header(struct mprintk *mp, const char *fmt, ...)
+{
+ va_list args;
+ int ret;
+
+ va_start(args, fmt);
+ ret = vmprintk_set_header(mp, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+EXPORT_SYMBOL(mprintk_set_header);
+
+/**
+ * mprintk - add a message to merging printk instance and flush it
+ * @mp: mprintk instance to use
+ * @fmt: format string (can be NULL)
+ *
+ * Add message formatted according to @fmt and arguments to @mp and
+ * flush it. If @fmt is NULL, only the latter operation occurs. NULL
+ * @fmt is allowed to avoid zero length formatting string warning from
+ * compiler.
+ */
+int mprintk(struct mprintk *mp, const char *fmt, ...)
+{
+ va_list args;
+ int ret;
+
+ va_start(args, fmt);
+ ret = vmprintk(mp, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+EXPORT_SYMBOL(mprintk);
+
#else
asmlinkage long sys_syslog(int type, char __user *buf, int len)
--
1.5.2.4
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 4/5] printk: add Documentation/printk.txt
2008-01-21 5:13 [PATCHSET] printk: implement printk_header() and merging printk, take #2 Tejun Heo
` (2 preceding siblings ...)
2008-01-21 5:13 ` [PATCH 3/5] printk: implement merging printk Tejun Heo
@ 2008-01-21 5:13 ` Tejun Heo
2008-01-21 5:13 ` [PATCH 5/5] libata: make libata use printk_header() and mprintk Tejun Heo
2008-01-21 12:48 ` [PATCHSET] printk: implement printk_header() and merging printk, take #2 Matthew Wilcox
5 siblings, 0 replies; 12+ messages in thread
From: Tejun Heo @ 2008-01-21 5:13 UTC (permalink / raw)
To: randy.dunlap, daniel.ritz-ml, matthew, jeff, linux-kernel,
linux-ide
Cc: Tejun Heo
Add Documentation/printk.txt which explains printk, mprintk and their
friends.
Signed-off-by: Tejun Heo <htejun@gmail.com>
---
Documentation/00-INDEX | 2 +
Documentation/printk.txt | 711 ++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 713 insertions(+), 0 deletions(-)
create mode 100644 Documentation/printk.txt
diff --git a/Documentation/00-INDEX b/Documentation/00-INDEX
index c3014df..3271b75 100644
--- a/Documentation/00-INDEX
+++ b/Documentation/00-INDEX
@@ -310,6 +310,8 @@ powerpc/
- directory with info on using Linux with the PowerPC.
preempt-locking.txt
- info on locking under a preemptive kernel.
+printk.txt
+ - info on printk and mprintk.
prio_tree.txt
- info on radix-priority-search-tree use for indexing vmas.
ramdisk.txt
diff --git a/Documentation/printk.txt b/Documentation/printk.txt
new file mode 100644
index 0000000..dc24e9c
--- /dev/null
+++ b/Documentation/printk.txt
@@ -0,0 +1,711 @@
+printk and mprintk
+==================
+Tejun Heo <teheo@suse.de>, January 18 2008
+
+This document describes printk and mprintk.
+
+TABLE OF CONTENTS
+
+[1] printk
+ [1-1] What is printk and how does it operate?
+ [1-2] Log level
+ [1-2-1] What is log level and how do I use it?
+ [1-2-2] How the log level is treated by kernel and logging tools.
+ [1-3] Timestamps
+ [1-4] Multiline messages and printk_header
+ [1-5] printk's friends
+
+[2] mprintk - the merging printk
+ [2-1] What is mprintk?
+ [2-2] How do I use mprintk?
+ [2-2-1] Initialization
+ [2-2-2] Assembling and printing
+ [2-2-3] Error handling
+ [2-3] Some guidelines
+ [2-4] mprintk's friends
+
+[3] How libata uses printk_header and mprintk
+
+
+[1] printk
+
+[1-1] What is printk and how does it operate?
+
+ int printk(const char *fmt, ...)
+
+printk is the equivalent of print for perl scripts, echo for shell
+scripts and much more closely printf(3) for userland C programs. It
+takes the same arguments as printf(3), formats the string the same way
+and spits the result out. printk is the kernel's primary way to emit
+human-readable messages.
+
+printf(3) prints formatted messages to the default destination -
+standard output. printk also has default destination or rather
+destinations. Messages printed out via printk are stored in a message
+buffer which can be retrieved either by syslog(2) system call or
+reading /proc/kmsg and then printed to one or more registered
+consoles.
+
+The ring buffer is the asynchronous way to access the messages.
+dmesg(1) dumps its content, klogd reads the messages and logs the
+result via syslog facility. The ring buffer is of fixed size which
+can be configured by the 'log_buf_len' kernel parameter. If a new
+message is printed and the ring buffer is full, it wraps around and
+writes over the old messages.
+
+On the other hand, the consoles behave mostly synchronously{1}. The
+most common console device is the virtual console (your graphics
+adapter and monitor). While the machine is booting, if you disable or
+escape from the pretty graphical boot screen, you'll see lots of
+kernel messages scrolling by before the userland starts to run. All
+those messages are from printk and your monitor is serving as a
+console device. Other examples of console devices include serial
+console{2} and netconsole{3}.
+
+The synchronous operation of console devices can be very expensive
+depending on which console devices are attached. For example,
+transferring 160 characters over 9600 baud rate serial line consumes
+around 18.75 milliseconds and the CPU won't be doing anything else
+other than pushing the bytes out.
+
+Accesses to the log buffer are synchronized and messages from separate
+printk invocations never get intermixed; however, there is no
+guarantee that two consecutive calls to printk will show up
+consecutively. printk calls from other threads can be printed
+inbetween.
+
+ Thread A Thread B
+
+ printk("hello "); printk("The answer is ");
+ printk("world!\n"); printk("42\n");
+
+The output can be
+
+ hello The answer is world!
+ 42
+
+or any other combination - 6 of them, so you shouldn't construct
+messages piece-by-piece by calling printk on substrings. You should
+build the complete message first and print it by calling printk once.
+As constructing a message from pieces can be a non-trival task, there
+is a helper mechanism called mprintk. It will be explained later.
+
+
+[1-2] Log level
+
+[1-2-1] What is log level and how do I use it?
+
+Another difference from printf(3) is that printk performs a bit of
+post-processing on the printed messages. Each line printed via printk
+has a log level which is priority or urgency of the message. Eight
+log levels are defined and have the following meanings.
+
+ KERN_EMERG : system is unusable
+ KERN_ALERT : action must be taken immediately
+ KERN_CRIT : critical conditions
+ KERN_ERR : error conditions
+ KERN_WARNING : warning conditions
+ KERN_NOTICE : normal but significant condition
+ KERN_INFO : informational
+ KERN_DEBUG : debug-level message
+
+If you search for the above constants in include/linux/kernel.h,
+you'll see that they are defined as string constants "<N>" where N is
+0 for EMERG and increments for each upto 7 for DEBUG. There's nothing
+magical about it. Lines which start with "<N>" has the priority of N.
+Because C's preprocessor merges string constants, simply putting the
+macro in front of a message suffices.
+
+ printk(KERN_WARNING "I'm a whiny kernel.\n");
+ printk("%sAm I too whiny?\n", KERN_WARNING);
+ printk("<%d>You don't think I'm too whiny, do you?\n", 4);
+
+Will output.
+
+ <4>I'm a whiny kernel.
+ <4>Am I too whiny?
+ <4>You don't think I'm too whiny, do you?
+
+But what happens when you don't specify log level? In such cases,
+printk automatically assigns the default log level which is
+KERN_WARNING by default but can be overridden using sysctl{4}, so
+
+ printk("Please tell me I don't whine too much\n");
+
+is mostly equivalent to
+
+ printk(KERN_WARNING "Please tell me I don't whine too much\n");
+
+Noticed 'mostly'? The output will be different if the message doesn't
+start a new line. Please recall that log level is per-line and thus
+log level string doesn't have any meaning when it's not at the start
+of a line.
+
+ printk(KERN_NOTICE "Why don't you notice me? ");
+ printk(KERN_EMERGE "Do I have to say louder?\n");
+
+The above will result in the following string.
+
+ <5>Why don't you notice me? <0>Do I have to say louder
+
+And printk will treat it as a NOTICE message whose content is
+
+ Why don't you notice me? <0>Do I have to say louder
+
+Putting log level in the middle of string doesn't do anything to the
+log level. It just gets printed verbatim. This is another reason to
+avoid constructing messages piece-by-piece by calling printk multiple
+times. Let's go back to the hello world example and add log levels
+there.
+
+ Thread A Thread B
+
+ printk(KERN_ERR "hello "); printk(KERN_INFO "The answer is ");
+ printk("world!\n"); printk("42\n");
+
+The end result can be
+
+ <3>hello <6>The answer is 42
+ <4>world
+
+The first line is ERR message with weird "<6>" in it and the second
+line is WARNING message where the log level is automatically assigned
+by printk.
+
+Another thing to note about log level handling is that printk
+maintains log level in a multiline message.
+
+ printk(KERN_INFO "whine0\nwhine1\n" KERN_ERR "whine2\nwhine3\n");
+
+Becomes
+
+ <6>whine0
+ <6>whine1
+ <3>whine2
+ <3>whine3
+
+
+[1-2-2] How the log level is treated by kernel and logging tools.
+
+You probably have never noticed the log level markup in the dmesg(1)
+output, /var/log/messages or kernel messages printed on your monitor.
+This is because log level is treated specially. When message buffer
+is accessed via syslog(2) or /proc/kmsg, the log level is printed
+verbatim but the reading program - often klogd(8) or dmesg(1) -
+recognizes the log levels, strips them and routes or treats the
+messages accordingly. You can read the raw messages with the log
+level by stopping klogd(8) and executing "cat /proc/kmsg".
+
+For console devices, printk itself performs similar function. The log
+level is stripped before being submitted to console drivers and
+messages are filtered according to the console log level such that low
+priority messages don't clutter consoles. Console log level can be
+adjusted using either syslog(2) system call or kernel.printk sysctl
+node{4}.
+
+
+[1-3] Timestamps
+
+Another post-processing performed by printk is prepending timestamp.
+When enabled, the kernel's conception of time since boot or resume is
+added between the log level and the actual message. The following is
+excerpt from libata probing messages.
+
+ <6>[ 114.971205] ata8: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
+ <6>[ 114.989200] ata8.00: HPA detected: current 156299375, native 156301488
+ <6>[ 115.007362] ata8.00: ATA-7: WDC WD800JD-00MSA1, 10.01E01, max UDMA/133
+ <6>[ 115.024879] ata8.00: 156299375 sectors, multi 16: LBA48 NCQ (depth 31/32)
+ <6>[ 115.043885] ata8.00: configured for UDMA/133
+
+The number before "." is seconds and after is nanoseconds. It's
+kernel's conception of time and may not match actual wall clock
+depending on power saving setting and other things.
+
+Timestamp is enabled at kernel compile time using CONFIG_PRINTK_TIME
+but it can also be enabled or disabled when booting by specifying
+"printk.time=1" as kernel boot parameter. In addition, by echoing "0"
+or "1" to /sys/module/printk/parameters/printk_time, you can control
+it while the system is running.
+
+klogd(8) automatically prepends timestamps when logging kernel
+messages, so printk timestamp is somewhat redundant; however, printk
+timestamp has the following benefits making it better suited for
+debugging.
+
+* klogd(8) only knows when it read the messages. It can't tell when
+ the message was generated. For example, during boot or resume,
+ userspace is not running and when klogd(8) finally runs it can't
+ tell what happened when and just puts the same timestamp on all the
+ accumulated messages.
+
+* It uses kernel's conception of time and at times this provides
+ better insight into what's going on. For example, if there's a bug
+ in kernel's timer code, kernel's conception of time can be stalled
+ or delayed while gettimeofday(2) still returns valid values.
+
+* Reading messages from the console or running dmesg(1) to dump the
+ message buffer is simpler than having klogd(8) running. Having
+ timestamps available when using simpler methods helps debugging.
+
+There are discussions of automatically stripping and handling
+timestamps from dmesg(1) and klogd(8) to remove the timestamps
+automatically.
+
+
+[1-4] Multiline messages and printk_header
+
+ int printk_header(const char *header, const char *fmt, ...)
+
+Kernel messages are usually fitted to 80 column as many people use 80
+column console or terminal to print out and view log messages, but, at
+times, there are more things to say than fits into one 80 column line.
+
+For example, when an ATA command fails, libata reports the taskfile
+registers for the failed command and the result taskfile registers.
+Both have similar formats and each nearly fills up 80 column. Such
+messages can be printed with separate calls to printk or as a single
+call to printk where the output string contains newline inside it.
+For simplicity, I'll just use simplified string constants for the rest
+of this section.
+
+ printk(KERN_ERR "ata1.00: cmd 60/01:00:e0:71:02/00:00:00:00:00/40\n");
+ printk(KERN_ERR "ata1.00: res 40/00:34:de:71:02/00:00:00:00:00/40\n");
+
+Or
+
+ printk(KERN_ERR "ata1.00: cmd 60/01:00:e0:71:02/00:00:00:00:00/40\n"
+ "ata1.00: res 40/00:34:de:71:02/00:00:00:00:00/40\n");
+
+Both will print about the same thing but the latter has the benefit
+that the message won't break up in the middle. Another twist is that
+there can be multiple commands in flight, so the output can look like
+the following.
+
+ ata1.00: cmd 60/57:00:69:ab:03/00:00:00:00:00/40
+ ata1.00: res 40/00:14:cc:ab:03/00:00:00:00:00/40
+ ata1.00: cmd 60/0c:08:c0:ab:03/00:00:00:00:00/40
+ ata1.00: res 40/00:14:cc:ab:03/00:00:00:00:00/40
+ ata1.00: cmd 60/80:18:e8:aa:03/00:00:00:00:00/40
+ ata1.00: res 40/00:14:cc:ab:03/00:00:00:00:00/40
+
+Which is pretty confusing to the eyes. It would be better if there is
+some indication of message boundaries.
+
+ ata1.00: cmd 60/57:00:69:ab:03/00:00:00:00:00/40
+ res 40/00:14:cc:ab:03/00:00:00:00:00/40
+ ata1.00: cmd 60/0c:08:c0:ab:03/00:00:00:00:00/40
+ res 40/00:14:cc:ab:03/00:00:00:00:00/40
+ ata1.00: cmd 60/80:18:e8:aa:03/00:00:00:00:00/40
+ res 40/00:14:cc:ab:03/00:00:00:00:00/40
+
+Okay, now it gives us clear visual clue where each multiline message
+starts, so combining the above atomic multiline message and visual
+clue by indenting, the driver should do the following.
+
+ printk(KERN_ERR "ata1.00: cmd 60/01:00:e0:71:02/00:00:00:00:00/40\n"
+ " res 40/00:34:de:71:02/00:00:00:00:00/40\n");
+
+However, this is not only clumsy but also difficult to get right. For
+example, the number of ATA ports in a machine can go over ten, in
+which case the port identification part becomes longer by one
+character and the indentation should too. This is the problem
+printk_header solves. It has a notion of message header and
+automatically prepends it to or indents messages to pretty-print
+multiline messages. The above example can be done using printk_header
+like the following.
+
+ printk_header(KERN_ERR "ata1.00: ",
+ "cmd 60/01:00:e0:71:02/00:00:00:00:00/40\n"
+ "res 40/00:34:de:71:02/00:00:00:00:00/40\n");
+
+printk_header will automatically prepend header to the first line and
+indent the second line the same amount such that it lines up with the
+first line. In the above example, log level is prepended to the
+header but printk_header also allows log level in front of each
+message line.
+
+ printk_header(KERN_ERR "whiny: ", KERN_DEBUG "it's me again\n"
+ KERN_INFO "I feel depressed today\n"
+ "The machine hates me\n");
+
+Will output
+
+ <7>whiny: it's me again
+ <6>whiny: I feel depressed today
+ <6> The machine hates me
+
+Note that the log level of the first message line trumped log level in
+the message header; also, the header is printed on the second line.
+This is because messages of different log levels can be routed
+differently and end up in different files or partially suppressed.
+printk_header prints out header once for each log level such that all
+differently routed messages have proper headers.
+
+As seen above, printk_header supports switching log level inside a
+multiline message but it's probably best to stick with a log level in
+a multiline message.
+
+
+[1-5] printk's friends
+
+int vprintk(const char *fmt, va_list args)
+
+ Identical to printk but takes va_list @args instead of argument
+ list.
+
+int vprintk_header(const char *header, const char *fmt, va_list args)
+
+ Identical to printk_header but takes va_list @args instead of
+ argument list.
+
+int __printk_ratelimit(int ratelimit_jiffies, int ratelimit_burst)
+
+ Rate-limited printk. Not more than one kernel message every
+ @ratelimit_jiffies to make a denial-of-service attack impossible.
+ @ratelimit_burst messages are allowed before ratelimit kicks in.
+
+int printk_ratelimit(void)
+
+ Rate-limited printk which uses standard limit and burst
+ parameters. Default parameters can be tuned using sysctl{5}.
+
+bool printk_timed_ratelimit(unsigned long *caller_jiffies,
+ unsigned int interval_msecs)
+
+ Caller-controlled printk ratelimiting. This function returns true
+ if more than @interval_msecs milliseconds have elapsed since the
+ last time it returned true.
+
+
+[2] mprintk - the merging printk
+
+[2-1] What is mprintk?
+
+Let's go back to the libata error message example. Actual ATA error
+message for a failed ATAPI command looks like the following.
+
+ ata1.00: cmd a0/01:00:00:00:00/00:00:00:00:00/b0 tag 0 dma 8 in
+ cdb 25 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
+ res 40/00:03:00:00:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
+
+On the first line, "dma 8 in" indicates that the failed command DMAs 8
+bytes from the drive to host memory. This segment of message is
+printed only for commands which transfer data. The second line
+reports the SCSI CDB issued to the drive and is only meaningful for
+the ATAPI PACKET command and thus omitted for all other commands. The
+last line reports the status of TF registers and as libata doesn't
+load TF registers after a timeout it should have been omitted but that
+isn't implemented yet.
+
+The example shows you how a message can be composed of multiple parts
+which can be included or omitted depending on the information to
+report. This happens quite often. Another example in libata would be
+the device configuration message.
+
+There are three ways to assemble these multi-part messages.
+
+* Calling printk() on partial message segments. This used to be quite
+ common but has a problem - the message can break up if someone else
+ prints something in the middle.
+
+* Prepping a temp buffer and building message piece-by-piece using
+ snprintf(). This is the most generic method but corner case
+ handling can be tedious and, on overflow, messages can be lost
+ unnoticed if overflow detection isn't properly done.
+
+* Collecting all the partial data and calling printk() once with all
+ the parameters. This is often combined with the second. This
+ usually works but printing messages becomes non-trivial programming
+ problem and can get quite tedious if the message format varies
+ depending on data.
+
+None of the above was satisfactory, so mprintk - merging printk - was
+implemented. It's basically a helper to construct a message
+piece-by-piece into the specified buffer. The caller still has to
+care about buffer size and how the buffer is allocated but mprintk
+makes it almost trivial.
+
+* DEFINE_MPRINTK() macro makes it easy to define a mprintk instance
+ with on-stack buffer. Malloc'd buffer can also be used.
+
+* Messages are never lost. On buffer overflow, all queued and to be
+ queued messages are printed followed by a warning message and stack
+ dump. The warning message and stack dump are printed once per
+ mprintk instance. Also, the caller doesn't have to handle buffer
+ allocation failure. If buffer is initialized to NULL, mprintk
+ simply bypasses messages to printk(). As free() can cope with NULL
+ pointer too, allocation failure doesn't require any extra care.
+
+* Has good support for multiline messages. A mprintk instance can
+ have header associated with it and the header can have log level.
+ Header log level is used if a message chunk doesn't specify log
+ level explicitly. When log level is specified explicitly in a
+ message chunk, the log level is applied to the chunk only.
+
+
+[2-2] How do I use mprintk?
+
+[2-2-1] Initialization
+
+ MPRINTK_INITIALIZER(buf, size)
+ DEFINE_MPRINTK(name, size)
+ void mprintk_init(struct mprintk *mp, char *buf, size_t size)
+
+struct mprintk is the data structure used to keep track of the merge
+buffer. This can be allocated anywhere but defining as a local
+variable for the block containing the message assembling code makes
+sense for most cases. struct mprintk doesn't contain buffer space for
+the string. It needs to be defined separately and mprintk should be
+initialized with the pointer to and the size of the buffer.
+
+MPRINTK_INITIALIZER() can be used to initialize mprintk instance.
+
+ char mp_buf[2 * 80];
+ struct mprintk mp0 = MPRINTK_INITIALIZER(mp_buf, 2 * 80);
+ struct mprintk mp1 = MPRINTK_INITIALIZER(kmalloc(512, GFP_KERNEL), 512);
+ struct mprintk mp2 = MPRINTK_INITIALIZER(A_struct->buffer, A_BUF_LEN);
+
+Function call variant - mprintk_init - can also be used.
+
+ struct mprintk mp;
+
+ mprinkt_init(&mp, kmalloc(MAX_MESSAGE_LEN, GFP_KERNEL), MAX_MESSAGE_LEN);
+
+Because defining both mprintk instance and string buffer on stack is
+the most common case, there's a shortcut for it.
+
+ DEFINE_MPRINTK(my_mp, 2 * 80);
+
+Which is equivalent to the following.
+
+ char __my_mp_buf[2 * 80];
+ struct mprintk my_mp = MPRINTK_INITIALIZER(__my_mp_buf, 2 * 80);
+
+Please keep in mind that MPRINTK_INITIALIZER allocates the string
+buffer on stack. If too much is allocated, stack overflow can happen.
+In most cases, a few hundred bytes should be fine and you shouldn't go
+over that anyway. More on this subject later in the guidelines
+section.
+
+
+[2-2-2] Assembling and printing
+
+ int mprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+ int mprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+ int mprintk(struct mprintk *mp, const char *fmt, va_list args)
+
+mprintk_set_header() sets the header of the message. This function
+can be called only once after initialization and should be called when
+the buffer is empty, that is, right after intialization or being
+flushed. Returns the length of the formatted string.
+
+mprintk_add() Appends the formatted string to the specified mprintk
+instance. Returns the length of the formatted string.
+
+mprintk() appends the formatted string to the specified mprintk
+instance, prints out the accumulated message and resets the buffer.
+Returns the length of the formatted string.
+
+Here's a simple example.
+
+ DEFINE_MPRINTK(mp, 2 * 80);
+
+ mprintk_set_header(&mp, KERN_INFO "Marvin: ");
+ mprintk_add(&mp, "Life.\n");
+ mprintk_add(&mp, "Don't talk to me ");
+ mprintk("about %s.\n", life);
+
+Which becomes
+
+ <6>Marvin: Life.
+ <6> Don't talk to me about life.
+
+mprintk allows log levels both in front of the header and in front of
+each message chunk (formatted string of each mprintk[_add]() call).
+Log levels specified in front of a message chunk applies only to that
+message chunk and has priority over the header log level. Message
+chunks without explicit log level use the header log level.
+
+ DEFINE_MPRINTK(mp, 4 * 80);
+
+ mprintk_set_header(&mp, KERN_INFO "Marvin: ");
+ mprintk_add(&mp, KERN_ERR "Here I am, brain the size of a planet and\n"
+ "they ask me to take you down to the bridge.\n");
+ mprintk_add(&mp, "Call that job satisfaction?\n");
+ mprintk(&mp, "'Cos I don't.\n");
+
+Which becomes
+
+ <3>Marvin: Here I am, brain the size of a planet and
+ <3> they ask me to take you down to the bridge.
+ <6>Marvin: Call that job satisfaction?
+ <6> 'Cos I don't.
+
+Note how KERN_ERR is applied to the first message chunk while the
+header log level is used for the last message chunks which don't have
+explicit log level specified. The header is printed again on the
+third line because of log level change.
+
+Remember log level is only meaningful when a new line starts? That
+applies the same to mprintk message chunks. If a message chunk
+doesn't start a new line, log level in front of it will be treated as
+verbatim string.
+
+Also, mprintk doesn't allow switching log level in the middle of a
+message chunk. Don't do it.
+
+
+[2-2-3] Error handling
+
+One good thing about mprintk is that you don't have to pay attention
+to error handling. There can be two error conditions - buffer
+overflow and NULL buffer due to allocation failure.
+
+If adding a new message chunk overflows the buffer, mprintk prints out
+the accumulated message followed by the new message chunk which caused
+overflow. If the overflow is the first one since mprintk
+initialization, a warning message and stack dump are printed to aid
+debugging.
+
+In rare cases, buffer overflow can also happen while setting the
+header, if this happens, it's handled the same way as message chunk
+overflow; however, after such a failure, if the messasge is multiline,
+lines after the first one won't have proper header, indentation or
+header log level - the default log level, WARNING, will be used for
+lines without explicit log level.
+
+When buffer is allocated using kmalloc(), the allocation might fail.
+mprintk allows NULL buffer initialization. In which case, mprintk
+simply forwards messages to printk. As in the header overflow case,
+header handling can be broken but no message is lost.
+
+All in all, you don't need to do any error handling when using
+mprintk. It's just like printk. It's guaranteed to deliver the
+message and there's no need to check the return values.
+
+ struct mprintk mp = MPRINTK_INITIALIZER(kmalloc(512, GFP_KERNEL), 512);
+ int i;
+
+ mprintk_set_header(&mp, "Beeblebrox: ");
+ for (i = 0; i < 5; i++)
+ mprintk_add(&mp, "Yeah. Listen, I'm Zaphod Beeblebrox,\n"
+ "my father was Zaphod Beeblebrox the Second,\n"
+ "my grandfather Zaphod Beeblebrox the Third...\n");
+ mprintk(&mp, "Rubbish...\n");
+ kfree(mp->buf);
+
+The above code segment will print 16 lines sans one overflow message
+and stack dump no matter what and won't leak memory.
+
+
+[2-3] Some guidelines
+
+* Don't build gigantic messages. Don't span over a few lines. Just
+ put what really needs to be an atomic message into one message.
+ Keep in mind that printk silently clips messages at 1k.
+
+* Prefer on-stack buffer and when using on-stack buffer use
+ DEFINE_MPRINTK(). If you observe the previous guideline, on-stack
+ buffer should be sufficient. It's the simplest and can't leak
+ memory.
+
+* With the header, indentaion and automatic log level adjustments, the
+ end result can be a bit longer. Give it some extra room. I find it
+ useful to specify buffer length in multiples of 80 as lines
+ shouldn't go over 80 column anyway. If the message can be four
+ lines long, specify 4 * 80.
+
+* Specify log level at the header and refrain from overriding log
+ level from message chunks unless necessary. If you encounter an
+ error condition while building an informational message, printing an
+ error message with a separate call to printk[_header]() and resuming
+ building the informational message if possible is usually the right
+ thing to do.
+
+
+[2-4] mprintk's friends
+
+int vmprintk_set_header(struct mprintk *mp, const char *fmt, va_list args)
+
+ Identical to mprintk_set_header but takes va_list @args instead of
+ argument list.
+
+int vmprintk_add(struct mprintk *mp, const char *fmt, va_list args)
+
+ Identical to mprintk_add but takes va_list @args instead of
+ argument list.
+
+int vmprintk(struct mprintk *mp, const char *fmt, va_list args)
+
+ Identical to mprintk but takes va_list @args instead of argument
+ list.
+
+
+[3] How libata uses printk_header and mprintk
+
+Me being a libata guy, the first user of printk_header and mprintk is
+libata. libata has printk helpers at each level - port, link and
+device. Let's take a look at the port one.
+
+ int ata_port_printk(struct ata_port *ap, const char *lv,
+ const char *fmt, ...)
+ {
+ va_list args;
+ char hbuf[16];
+ int ret;
+
+ snprintf(hbuf, sizeof(hbuf), "%sata%u: ", lv, ap->print_id);
+
+ va_start(args, fmt);
+ ret = vprintk_header(hbuf, fmt, args);
+ va_end(args);
+
+ return ret;
+ }
+
+It creates a header and calls vprintk_header() with it and passes the
+format string and arguments. Note the separate @lv argument. This is
+remnant of the previous define-based implementation which didn't use
+printk_header and thus had to manually put the message level in front
+of the header. With printk_header, the formatted string can carry the
+log level in front of it and printk_header will do the right thing.
+
+Also, there is a port-level helper to set header of a mprintk buffer.
+
+ void ata_port_mp_header(struct ata_port *ap, const char *lv,
+ struct mprintk *mp)
+ {
+ mprintk_set_header(mp, "%sata%u: ", lv, ap->print_id);
+ }
+
+After initializing mprintk and calling the above function,
+mprintk_add() and mprintk() can be used freely to assemble and print
+messages. For examples, take a look at ata_dev_configure() in
+drivers/ata/libata-core.c and ata_eh_link_report() in
+drivers/ata/libata-eh.c. Note that both functions use ap->sector_buf.
+This is 512 byte buffer owned by the EH thread which happens to be the
+only thread which does EH reporting and device configuration.
+
+Happy hacking.
+
+
+REFERENCES
+
+{1} On SMP, if a CPU does printk while another one is executing
+ console drivers to push out messages, the new message would simply
+ be queued and printk returns.
+
+{2} Documentation/serial-console.txt
+
+{3} Documentation/networking/netconsole.txt
+ Note that netconsole can't be the primary console - the one which
+ provides standard IOs to init - as it can't read from the user.
+ Also, its synchronisity is further limited. On write completion,
+ all that can be assured is that the packets containing the message
+ have been sent. Whether or when the message has arrived on the
+ destination is unknown.
+
+{4} Documentation/sysctl/kernel.txt:printk
+
+{5} Documentation/sysctl/kernel.txt:printk_ratelimit,printk_ratelimit_burst
+
--
1.5.2.4
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH 5/5] libata: make libata use printk_header() and mprintk
2008-01-21 5:13 [PATCHSET] printk: implement printk_header() and merging printk, take #2 Tejun Heo
` (3 preceding siblings ...)
2008-01-21 5:13 ` [PATCH 4/5] printk: add Documentation/printk.txt Tejun Heo
@ 2008-01-21 5:13 ` Tejun Heo
2008-01-21 12:48 ` [PATCHSET] printk: implement printk_header() and merging printk, take #2 Matthew Wilcox
5 siblings, 0 replies; 12+ messages in thread
From: Tejun Heo @ 2008-01-21 5:13 UTC (permalink / raw)
To: randy.dunlap, daniel.ritz-ml, matthew, jeff, linux-kernel,
linux-ide
Cc: Tejun Heo
Reimplement libata printk helpers using printk_header, implement
helpers to initialize mprintk and use mprintk during device
configuration and EH reporting.
This fixes various formatting related problems of libata messages such
as misaligned multiline messages, decoded register lines with leading
headers making them difficult to tell to which error they belong to,
awkward manual indents and complex message printing logics. More
importantly, by making message assembly flexible, this patch makes
future changes to device configuration and EH reporting easier.
Signed-off-by: Tejun Heo <htejun@gmail.com>
---
drivers/ata/libata-core.c | 202 +++++++++++++++++++++++++++----------------
drivers/ata/libata-eh.c | 150 +++++++++++++++-----------------
drivers/ata/libata-pmp.c | 5 +-
drivers/ata/libata-scsi.c | 6 +-
drivers/ata/sata_inic162x.c | 2 +-
drivers/ata/sata_nv.c | 4 +-
include/linux/libata.h | 35 ++++----
7 files changed, 223 insertions(+), 181 deletions(-)
diff --git a/drivers/ata/libata-core.c b/drivers/ata/libata-core.c
index 6380726..248e1c9 100644
--- a/drivers/ata/libata-core.c
+++ b/drivers/ata/libata-core.c
@@ -125,6 +125,79 @@ MODULE_LICENSE("GPL");
MODULE_VERSION(DRV_VERSION);
+int ata_port_printk(struct ata_port *ap, const char *lv, const char *fmt, ...)
+{
+ va_list args;
+ char hbuf[16];
+ int ret;
+
+ snprintf(hbuf, sizeof(hbuf), "%sata%u: ", lv, ap->print_id);
+
+ va_start(args, fmt);
+ ret = vprintk_header(hbuf, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+
+int ata_link_printk(struct ata_link *link, const char *lv, const char *fmt, ...)
+{
+ va_list args;
+ char hbuf[16];
+ int ret;
+
+ if (link->ap->nr_pmp_links)
+ snprintf(hbuf, sizeof(hbuf), "%sata%u.%02u: ",
+ lv, link->ap->print_id, link->pmp);
+ else
+ snprintf(hbuf, sizeof(hbuf), "%sata%u: ",
+ lv, link->ap->print_id);
+
+ va_start(args, fmt);
+ ret = vprintk_header(hbuf, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+
+int ata_dev_printk(struct ata_device *dev, const char *lv, const char *fmt, ...)
+{
+ va_list args;
+ char hbuf[16];
+ int ret;
+
+ snprintf(hbuf, sizeof(hbuf), "%sata%u.%02u: ",
+ lv, dev->link->ap->print_id, dev->link->pmp + dev->devno);
+
+ va_start(args, fmt);
+ ret = vprintk_header(hbuf, fmt, args);
+ va_end(args);
+
+ return ret;
+}
+
+void ata_port_mp_header(struct ata_port *ap, const char *lv, struct mprintk *mp)
+{
+ mprintk_set_header(mp, "%sata%u: ", lv, ap->print_id);
+}
+
+void ata_link_mp_header(struct ata_link *link, const char *lv,
+ struct mprintk *mp)
+{
+ if (link->ap->nr_pmp_links)
+ mprintk_set_header(mp, "%sata%u.%02u: ",
+ lv, link->ap->print_id, link->pmp);
+ else
+ mprintk_set_header(mp, "%sata%u: ", lv, link->ap->print_id);
+}
+
+void ata_dev_mp_header(struct ata_device *dev, const char *lv,
+ struct mprintk *mp)
+{
+ mprintk_set_header(mp, "%sata%u.%02u: ", lv, dev->link->ap->print_id,
+ dev->link->pmp + dev->devno);
+}
+
/**
* ata_tf_to_fis - Convert ATA taskfile to SATA FIS structure
* @tf: Taskfile to convert
@@ -2046,18 +2119,16 @@ static inline u8 ata_dev_knobble(struct ata_device *dev)
return ((ap->cbl == ATA_CBL_SATA) && (!ata_id_is_sata(dev->id)));
}
-static void ata_dev_config_ncq(struct ata_device *dev,
- char *desc, size_t desc_sz)
+static void ata_dev_config_ncq(struct ata_device *dev, struct mprintk *mp)
{
struct ata_port *ap = dev->link->ap;
int hdepth = 0, ddepth = ata_id_queue_depth(dev->id);
- if (!ata_id_has_ncq(dev->id)) {
- desc[0] = '\0';
+ if (!ata_id_has_ncq(dev->id))
return;
- }
+
if (dev->horkage & ATA_HORKAGE_NONCQ) {
- snprintf(desc, desc_sz, "NCQ (not used)");
+ mprintk_add(mp, ", NCQ (not used)");
return;
}
if (ap->flags & ATA_FLAG_NCQ) {
@@ -2066,9 +2137,9 @@ static void ata_dev_config_ncq(struct ata_device *dev,
}
if (hdepth >= ddepth)
- snprintf(desc, desc_sz, "NCQ (depth %d)", ddepth);
+ mprintk_add(mp, ", NCQ (depth %d)", ddepth);
else
- snprintf(desc, desc_sz, "NCQ (depth %d/%d)", hdepth, ddepth);
+ mprintk_add(mp, ", NCQ (depth %d/%d)", hdepth, ddepth);
}
/**
@@ -2090,8 +2161,8 @@ int ata_dev_configure(struct ata_device *dev)
struct ata_eh_context *ehc = &dev->link->eh_context;
int print_info = ehc->i.flags & ATA_EHI_PRINTINFO;
const u16 *id = dev->id;
+ struct mprintk mp = MPRINTK_INITIALIZER(ap->sector_buf, ATA_SECT_SIZE);
unsigned int xfer_mask;
- char revbuf[7]; /* XYZ-99\0 */
char fwrevbuf[ATA_ID_FW_REV_LEN+1];
char modelbuf[ATA_ID_PROD_LEN+1];
int rc;
@@ -2105,6 +2176,8 @@ int ata_dev_configure(struct ata_device *dev)
if (ata_msg_probe(ap))
ata_dev_printk(dev, KERN_DEBUG, "%s: ENTER\n", __FUNCTION__);
+ ata_dev_mp_header(dev, KERN_INFO, &mp);
+
/* set horkage */
dev->horkage |= ata_dev_blacklisted(dev);
@@ -2153,51 +2226,44 @@ int ata_dev_configure(struct ata_device *dev)
ata_id_c_string(dev->id, modelbuf, ATA_ID_PROD,
sizeof(modelbuf));
- /* ATA-specific feature tests */
if (dev->class == ATA_DEV_ATA) {
+ /* ATA-specific feature tests */
if (ata_id_is_cfa(id)) {
- if (id[162] & 1) /* CPRM may make this media unusable */
+ /* CPRM may make this media unusable */
+ if ((id[162] & 1) && print_info)
ata_dev_printk(dev, KERN_WARNING,
"supports DRM functions and may "
"not be fully accessable.\n");
- snprintf(revbuf, 7, "CFA");
+ mprintk_add(&mp, "CFA: ");
} else
- snprintf(revbuf, 7, "ATA-%d", ata_id_major_version(id));
+ mprintk_add(&mp, "ATA-%d: ", ata_id_major_version(id));
+
+ mprintk_add(&mp, "%s, %s, max %s\n",
+ modelbuf, fwrevbuf, ata_mode_string(xfer_mask));
dev->n_sectors = ata_id_n_sectors(id);
+ mprintk_add(&mp, "%Lu sectors",
+ (unsigned long long)dev->n_sectors);
- if (dev->id[59] & 0x100)
+ if (dev->id[59] & 0x100) {
dev->multi_count = dev->id[59] & 0xff;
+ mprintk_add(&mp, ", multi %u", dev->multi_count);
+ }
if (ata_id_has_lba(id)) {
- const char *lba_desc;
- char ncq_desc[20];
-
- lba_desc = "LBA";
dev->flags |= ATA_DFLAG_LBA;
+ mprintk_add(&mp, ", LBA");
+
if (ata_id_has_lba48(id)) {
dev->flags |= ATA_DFLAG_LBA48;
- lba_desc = "LBA48";
-
+ mprintk_add(&mp, "48");
if (dev->n_sectors >= (1UL << 28) &&
ata_id_has_flush_ext(id))
dev->flags |= ATA_DFLAG_FLUSH_EXT;
}
/* config NCQ */
- ata_dev_config_ncq(dev, ncq_desc, sizeof(ncq_desc));
-
- /* print device info to dmesg */
- if (ata_msg_drv(ap) && print_info) {
- ata_dev_printk(dev, KERN_INFO,
- "%s: %s, %s, max %s\n",
- revbuf, modelbuf, fwrevbuf,
- ata_mode_string(xfer_mask));
- ata_dev_printk(dev, KERN_INFO,
- "%Lu sectors, multi %u: %s %s\n",
- (unsigned long long)dev->n_sectors,
- dev->multi_count, lba_desc, ncq_desc);
- }
+ ata_dev_config_ncq(dev, &mp);
} else {
/* CHS */
@@ -2213,27 +2279,13 @@ int ata_dev_configure(struct ata_device *dev)
dev->sectors = id[56];
}
- /* print device info to dmesg */
- if (ata_msg_drv(ap) && print_info) {
- ata_dev_printk(dev, KERN_INFO,
- "%s: %s, %s, max %s\n",
- revbuf, modelbuf, fwrevbuf,
- ata_mode_string(xfer_mask));
- ata_dev_printk(dev, KERN_INFO,
- "%Lu sectors, multi %u, CHS %u/%u/%u\n",
- (unsigned long long)dev->n_sectors,
- dev->multi_count, dev->cylinders,
- dev->heads, dev->sectors);
- }
+ mprintk_add(&mp, ", CHS %u/%u/%u",
+ dev->cylinders, dev->heads, dev->sectors);
}
dev->cdb_len = 16;
- }
-
- /* ATAPI-specific feature tests */
- else if (dev->class == ATA_DEV_ATAPI) {
- const char *cdb_intr_string = "";
- const char *atapi_an_string = "";
+ } else if (dev->class == ATA_DEV_ATAPI) {
+ /* ATAPI-specific feature tests */
u32 sntf;
rc = atapi_cdb_len(id);
@@ -2246,6 +2298,14 @@ int ata_dev_configure(struct ata_device *dev)
}
dev->cdb_len = (unsigned int) rc;
+ mprintk_add(&mp, "ATAPI: %s, %s, max %s", modelbuf, fwrevbuf,
+ ata_mode_string(xfer_mask));
+
+ if (ata_id_cdb_intr(dev->id)) {
+ dev->flags |= ATA_DFLAG_CDB_INTR;
+ mprintk_add(&mp, ", CDB intr");
+ }
+
/* Enable ATAPI AN if both the host and device have
* the support. If PMP is attached, SNTF is required
* to enable ATAPI AN to discern between PHY status
@@ -2265,22 +2325,9 @@ int ata_dev_configure(struct ata_device *dev)
"(err_mask=0x%x)\n", err_mask);
else {
dev->flags |= ATA_DFLAG_AN;
- atapi_an_string = ", ATAPI AN";
+ mprintk_add(&mp, ", ATAPI AN");
}
}
-
- if (ata_id_cdb_intr(dev->id)) {
- dev->flags |= ATA_DFLAG_CDB_INTR;
- cdb_intr_string = ", CDB intr";
- }
-
- /* print device info to dmesg */
- if (ata_msg_drv(ap) && print_info)
- ata_dev_printk(dev, KERN_INFO,
- "ATAPI: %s, %s, max %s%s%s\n",
- modelbuf, fwrevbuf,
- ata_mode_string(xfer_mask),
- cdb_intr_string, atapi_an_string);
}
/* determine max_sectors */
@@ -2295,23 +2342,18 @@ int ata_dev_configure(struct ata_device *dev)
dev->flags |= ATA_DFLAG_DIPM;
}
- if (dev->horkage & ATA_HORKAGE_DIAGNOSTIC) {
+ if ((dev->horkage & ATA_HORKAGE_DIAGNOSTIC) && print_info) {
/* Let the user know. We don't want to disallow opens for
rescue purposes, or in case the vendor is just a blithering
idiot */
- if (print_info) {
- ata_dev_printk(dev, KERN_WARNING,
-"Drive reports diagnostics failure. This may indicate a drive\n");
- ata_dev_printk(dev, KERN_WARNING,
-"fault or invalid emulation. Contact drive vendor for information.\n");
- }
+ ata_dev_printk(dev, KERN_WARNING,
+ "Drive reports diagnostics failure. This may indicate a drive\n"
+ "fault or invalid emulation. Contact drive vendor for information.\n");
}
/* limit bridge transfers to udma5, 200 sectors */
if (ata_dev_knobble(dev)) {
- if (ata_msg_drv(ap) && print_info)
- ata_dev_printk(dev, KERN_INFO,
- "applying bridge limits\n");
+ mprintk_add(&mp, ", applying bridge limits");
dev->udma_mask &= ATA_UDMA5;
dev->max_sectors = ATA_MAX_SECTORS;
}
@@ -2336,6 +2378,10 @@ int ata_dev_configure(struct ata_device *dev)
if (ap->ops->dev_config)
ap->ops->dev_config(dev);
+ /* print device info to dmesg */
+ if (ata_msg_drv(ap) && print_info)
+ mprintk(&mp, "\n");
+
if (ata_msg_probe(ap))
ata_dev_printk(dev, KERN_DEBUG, "%s: EXIT, drv_stat = 0x%x\n",
__FUNCTION__, ata_chk_status(ap));
@@ -7579,6 +7625,12 @@ EXPORT_SYMBOL_GPL(sata_deb_timing_hotplug);
EXPORT_SYMBOL_GPL(sata_deb_timing_long);
EXPORT_SYMBOL_GPL(ata_dummy_port_ops);
EXPORT_SYMBOL_GPL(ata_dummy_port_info);
+EXPORT_SYMBOL_GPL(ata_port_printk);
+EXPORT_SYMBOL_GPL(ata_link_printk);
+EXPORT_SYMBOL_GPL(ata_dev_printk);
+EXPORT_SYMBOL_GPL(ata_port_mp_header);
+EXPORT_SYMBOL_GPL(ata_link_mp_header);
+EXPORT_SYMBOL_GPL(ata_dev_mp_header);
EXPORT_SYMBOL_GPL(ata_std_bios_param);
EXPORT_SYMBOL_GPL(ata_std_ports);
EXPORT_SYMBOL_GPL(ata_host_init);
diff --git a/drivers/ata/libata-eh.c b/drivers/ata/libata-eh.c
index 21a81cd..a7ad3e7 100644
--- a/drivers/ata/libata-eh.c
+++ b/drivers/ata/libata-eh.c
@@ -1786,17 +1786,12 @@ static void ata_eh_link_report(struct ata_link *link)
{
struct ata_port *ap = link->ap;
struct ata_eh_context *ehc = &link->eh_context;
- const char *frozen, *desc;
- char tries_buf[6];
+ struct mprintk mp = MPRINTK_INITIALIZER(ap->sector_buf, ATA_SECT_SIZE);
int tag, nr_failed = 0;
if (ehc->i.flags & ATA_EHI_QUIET)
return;
- desc = NULL;
- if (ehc->i.desc[0] != '\0')
- desc = ehc->i.desc;
-
for (tag = 0; tag < ATA_MAX_QUEUE; tag++) {
struct ata_queued_cmd *qc = __ata_qc_from_tag(ap, tag);
@@ -1813,33 +1808,25 @@ static void ata_eh_link_report(struct ata_link *link)
if (!nr_failed && !ehc->i.err_mask)
return;
- frozen = "";
- if (ap->pflags & ATA_PFLAG_FROZEN)
- frozen = " frozen";
+ if (ehc->i.dev)
+ ata_dev_mp_header(ehc->i.dev, KERN_ERR, &mp);
+ else
+ ata_link_mp_header(link, KERN_ERR, &mp);
- memset(tries_buf, 0, sizeof(tries_buf));
+ mprintk_add(&mp, "exception Emask 0x%x SAct 0x%x SErr 0x%x action 0x%x",
+ ehc->i.err_mask, link->sactive, ehc->i.serror,
+ ehc->i.action);
+ if (ap->pflags & ATA_PFLAG_FROZEN)
+ mprintk_add(&mp, " frozen");
if (ap->eh_tries < ATA_EH_MAX_TRIES)
- snprintf(tries_buf, sizeof(tries_buf) - 1, " t%d",
- ap->eh_tries);
+ mprintk_add(&mp, " t%d", ap->eh_tries);
+ mprintk_add(&mp, "\n");
- if (ehc->i.dev) {
- ata_dev_printk(ehc->i.dev, KERN_ERR, "exception Emask 0x%x "
- "SAct 0x%x SErr 0x%x action 0x%x%s%s\n",
- ehc->i.err_mask, link->sactive, ehc->i.serror,
- ehc->i.action, frozen, tries_buf);
- if (desc)
- ata_dev_printk(ehc->i.dev, KERN_ERR, "%s\n", desc);
- } else {
- ata_link_printk(link, KERN_ERR, "exception Emask 0x%x "
- "SAct 0x%x SErr 0x%x action 0x%x%s%s\n",
- ehc->i.err_mask, link->sactive, ehc->i.serror,
- ehc->i.action, frozen, tries_buf);
- if (desc)
- ata_link_printk(link, KERN_ERR, "%s\n", desc);
- }
+ if (ehc->i.desc[0] != '\0')
+ mprintk_add(&mp, "%s\n", ehc->i.desc);
if (ehc->i.serror)
- ata_port_printk(ap, KERN_ERR,
+ mprintk_add(&mp,
"SError: { %s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s}\n",
ehc->i.serror & SERR_DATA_RECOVERED ? "RecovData " : "",
ehc->i.serror & SERR_COMM_RECOVERED ? "RecovComm " : "",
@@ -1859,85 +1846,90 @@ static void ata_eh_link_report(struct ata_link *link)
ehc->i.serror & SERR_UNRECOG_FIS ? "UnrecFIS " : "",
ehc->i.serror & SERR_DEV_XCHG ? "DevExch " : "");
+ mprintk(&mp, NULL); /* flush link / device wide messages */
+
for (tag = 0; tag < ATA_MAX_QUEUE; tag++) {
+ static const char *dma_str[] = {
+ [DMA_BIDIRECTIONAL] = "bidi",
+ [DMA_TO_DEVICE] = "out",
+ [DMA_FROM_DEVICE] = "in",
+ };
+ static const char *prot_str[] = {
+ [ATA_PROT_PIO] = "pio",
+ [ATA_PROT_DMA] = "dma",
+ [ATA_PROT_NCQ] = "ncq",
+ [ATA_PROT_ATAPI] = "pio",
+ [ATA_PROT_ATAPI_DMA] = "dma",
+ };
struct ata_queued_cmd *qc = __ata_qc_from_tag(ap, tag);
struct ata_taskfile *cmd = &qc->tf, *res = &qc->result_tf;
const u8 *cdb = qc->cdb;
- char data_buf[20] = "";
- char cdb_buf[70] = "";
+ int need_newline = 0;
if (!(qc->flags & ATA_QCFLAG_FAILED) ||
qc->dev->link != link || !qc->err_mask)
continue;
- if (qc->dma_dir != DMA_NONE) {
- static const char *dma_str[] = {
- [DMA_BIDIRECTIONAL] = "bidi",
- [DMA_TO_DEVICE] = "out",
- [DMA_FROM_DEVICE] = "in",
- };
- static const char *prot_str[] = {
- [ATA_PROT_PIO] = "pio",
- [ATA_PROT_DMA] = "dma",
- [ATA_PROT_NCQ] = "ncq",
- [ATA_PROT_ATAPI] = "pio",
- [ATA_PROT_ATAPI_DMA] = "dma",
- };
-
- snprintf(data_buf, sizeof(data_buf), " %s %u %s",
- prot_str[qc->tf.protocol], qc->nbytes,
- dma_str[qc->dma_dir]);
- }
+ mprintk_add(&mp, "cmd %02x/%02x:%02x:%02x:%02x:%02x/"
+ "%02x:%02x:%02x:%02x:%02x/%02x tag %d",
+ cmd->command, cmd->feature, cmd->nsect,
+ cmd->lbal, cmd->lbam, cmd->lbah,
+ cmd->hob_feature, cmd->hob_nsect,
+ cmd->hob_lbal, cmd->hob_lbam, cmd->hob_lbah,
+ cmd->device, qc->tag);
+
+ if (qc->dma_dir != DMA_NONE)
+ mprintk_add(&mp, " %s %u %s",
+ prot_str[qc->tf.protocol],
+ qc->nbytes, dma_str[qc->dma_dir]);
+ mprintk_add(&mp, "\n");
if (is_atapi_taskfile(&qc->tf))
- snprintf(cdb_buf, sizeof(cdb_buf),
- "cdb %02x %02x %02x %02x %02x %02x %02x %02x "
- "%02x %02x %02x %02x %02x %02x %02x %02x\n ",
- cdb[0], cdb[1], cdb[2], cdb[3],
- cdb[4], cdb[5], cdb[6], cdb[7],
- cdb[8], cdb[9], cdb[10], cdb[11],
- cdb[12], cdb[13], cdb[14], cdb[15]);
-
- ata_dev_printk(qc->dev, KERN_ERR,
- "cmd %02x/%02x:%02x:%02x:%02x:%02x/%02x:%02x:%02x:%02x:%02x/%02x "
- "tag %d%s\n %s"
- "res %02x/%02x:%02x:%02x:%02x:%02x/%02x:%02x:%02x:%02x:%02x/%02x "
- "Emask 0x%x (%s)%s\n",
- cmd->command, cmd->feature, cmd->nsect,
- cmd->lbal, cmd->lbam, cmd->lbah,
- cmd->hob_feature, cmd->hob_nsect,
- cmd->hob_lbal, cmd->hob_lbam, cmd->hob_lbah,
- cmd->device, qc->tag, data_buf, cdb_buf,
- res->command, res->feature, res->nsect,
- res->lbal, res->lbam, res->lbah,
- res->hob_feature, res->hob_nsect,
- res->hob_lbal, res->hob_lbam, res->hob_lbah,
- res->device, qc->err_mask, ata_err_string(qc->err_mask),
- qc->err_mask & AC_ERR_NCQ ? " <F>" : "");
+ mprintk_add(&mp, "cdb %02x %02x %02x %02x %02x %02x %02x %02x "
+ "%02x %02x %02x %02x %02x %02x %02x %02x\n",
+ cdb[0], cdb[1], cdb[2], cdb[3],
+ cdb[4], cdb[5], cdb[6], cdb[7],
+ cdb[8], cdb[9], cdb[10], cdb[11],
+ cdb[12], cdb[13], cdb[14], cdb[15]);
+
+ mprintk_add(&mp, "res %02x/%02x:%02x:%02x:%02x:%02x/"
+ "%02x:%02x:%02x:%02x:%02x/%02x Emask 0x%x (%s)%s\n",
+ res->command, res->feature, res->nsect,
+ res->lbal, res->lbam, res->lbah,
+ res->hob_feature, res->hob_nsect,
+ res->hob_lbal, res->hob_lbam, res->hob_lbah,
+ res->device, qc->err_mask,
+ ata_err_string(qc->err_mask),
+ qc->err_mask & AC_ERR_NCQ ? " <F>" : "");
if (res->command & (ATA_BUSY | ATA_DRDY | ATA_DF | ATA_DRQ |
ATA_ERR)) {
if (res->command & ATA_BUSY)
- ata_dev_printk(qc->dev, KERN_ERR,
- "status: { Busy }\n");
+ mprintk_add(&mp, "status: { Busy } ");
else
- ata_dev_printk(qc->dev, KERN_ERR,
- "status: { %s%s%s%s}\n",
+ mprintk_add(&mp, "status: { %s%s%s%s} ",
res->command & ATA_DRDY ? "DRDY " : "",
res->command & ATA_DF ? "DF " : "",
res->command & ATA_DRQ ? "DRQ " : "",
res->command & ATA_ERR ? "ERR " : "");
+ need_newline = 1;
}
if (cmd->command != ATA_CMD_PACKET &&
(res->feature & (ATA_ICRC | ATA_UNC | ATA_IDNF |
- ATA_ABORTED)))
- ata_dev_printk(qc->dev, KERN_ERR,
- "error: { %s%s%s%s}\n",
+ ATA_ABORTED))) {
+ mprintk_add(&mp, "error: { %s%s%s%s}",
res->feature & ATA_ICRC ? "ICRC " : "",
res->feature & ATA_UNC ? "UNC " : "",
res->feature & ATA_IDNF ? "IDNF " : "",
res->feature & ATA_ABORTED ? "ABRT " : "");
+ need_newline = 1;
+ }
+
+ if (need_newline)
+ mprintk(&mp, "\n");
+ else
+ mprintk(&mp, NULL);
}
}
diff --git a/drivers/ata/libata-pmp.c b/drivers/ata/libata-pmp.c
index caef2bb..cc6e4ca 100644
--- a/drivers/ata/libata-pmp.c
+++ b/drivers/ata/libata-pmp.c
@@ -408,9 +408,8 @@ static int sata_pmp_configure(struct ata_device *dev, int print_info)
if (!(dev->flags & ATA_DFLAG_AN))
ata_dev_printk(dev, KERN_INFO,
- "Asynchronous notification not supported, "
- "hotplug won't\n work on fan-out "
- "ports. Use warm-plug instead.\n");
+ "Asynchronous notification not supported, hotplug won't\n"
+ "work on fan-out ports. Use warm-plug instead.\n");
}
return 0;
diff --git a/drivers/ata/libata-scsi.c b/drivers/ata/libata-scsi.c
index 14daf48..a486774 100644
--- a/drivers/ata/libata-scsi.c
+++ b/drivers/ata/libata-scsi.c
@@ -3207,9 +3207,9 @@ void ata_scsi_scan_host(struct ata_port *ap, int sync)
goto repeat;
}
- ata_port_printk(ap, KERN_ERR, "WARNING: synchronous SCSI scan "
- "failed without making any progress,\n"
- " switching to async\n");
+ ata_port_printk(ap, KERN_ERR,
+ "WARNING: synchronous SCSI scan failed without making any \n"
+ " progress, switching to async\n");
}
queue_delayed_work(ata_aux_wq, &ap->hotplug_task,
diff --git a/drivers/ata/sata_inic162x.c b/drivers/ata/sata_inic162x.c
index 323c087..c45bd38 100644
--- a/drivers/ata/sata_inic162x.c
+++ b/drivers/ata/sata_inic162x.c
@@ -502,7 +502,7 @@ static void inic_dev_config(struct ata_device *dev)
if (dev->n_sectors >= 1 << 28) {
ata_dev_printk(dev, KERN_ERR,
"ERROR: This driver doesn't support LBA48 yet and may cause\n"
- " data corruption on such devices. Disabling.\n");
+ " data corruption on such devices. Disabling.\n");
ata_dev_disable(dev);
}
}
diff --git a/drivers/ata/sata_nv.c b/drivers/ata/sata_nv.c
index ed5dc7c..7874f61 100644
--- a/drivers/ata/sata_nv.c
+++ b/drivers/ata/sata_nv.c
@@ -1788,8 +1788,8 @@ static void nv_swncq_ncq_stop(struct ata_port *ap)
"EH in SWNCQ mode,QC:qc_active 0x%X sactive 0x%X\n",
ap->qc_active, ap->link.sactive);
ata_port_printk(ap, KERN_ERR,
- "SWNCQ:qc_active 0x%X defer_bits 0x%X last_issue_tag 0x%x\n "
- "dhfis 0x%X dmafis 0x%X sdbfis 0x%X\n",
+ "SWNCQ: qc_active 0x%X defer_bits 0x%X last_issue_tag 0x%x\n"
+ " dhfis 0x%X dmafis 0x%X sdbfis 0x%X\n",
pp->qc_active, pp->defer_queue.defer_bits, pp->last_issue_tag,
pp->dhfis_bits, pp->dmafis_bits, pp->sdbfis_bits);
diff --git a/include/linux/libata.h b/include/linux/libata.h
index 124033c..c31ea05 100644
--- a/include/linux/libata.h
+++ b/include/linux/libata.h
@@ -773,6 +773,23 @@ static inline int ata_port_is_dummy(struct ata_port *ap)
return ap->ops == &ata_dummy_port_ops;
}
+extern int ata_port_printk(struct ata_port *ap, const char *lv,
+ const char *fmt, ...)
+ __attribute__ ((format (printf, 3, 4)));
+extern int ata_link_printk(struct ata_link *link, const char *lv,
+ const char *fmt, ...)
+ __attribute__ ((format (printf, 3, 4)));
+extern int ata_dev_printk(struct ata_device *dev, const char *lv,
+ const char *fmt, ...)
+ __attribute__ ((format (printf, 3, 4)));
+
+extern void ata_port_mp_header(struct ata_port *ap, const char *lv,
+ struct mprintk *mp);
+extern void ata_link_mp_header(struct ata_link *link, const char *lv,
+ struct mprintk *mp);
+extern void ata_dev_mp_header(struct ata_device *dev, const char *lv,
+ struct mprintk *mp);
+
extern void sata_print_link_status(struct ata_link *link);
extern void ata_port_probe(struct ata_port *);
extern void ata_bus_reset(struct ata_port *ap);
@@ -1023,24 +1040,6 @@ extern void ata_do_eh(struct ata_port *ap, ata_prereset_fn_t prereset,
ata_postreset_fn_t postreset);
/*
- * printk helpers
- */
-#define ata_port_printk(ap, lv, fmt, args...) \
- printk("%sata%u: "fmt, lv, (ap)->print_id , ##args)
-
-#define ata_link_printk(link, lv, fmt, args...) do { \
- if ((link)->ap->nr_pmp_links) \
- printk("%sata%u.%02u: "fmt, lv, (link)->ap->print_id, \
- (link)->pmp , ##args); \
- else \
- printk("%sata%u: "fmt, lv, (link)->ap->print_id , ##args); \
- } while(0)
-
-#define ata_dev_printk(dev, lv, fmt, args...) \
- printk("%sata%u.%02u: "fmt, lv, (dev)->link->ap->print_id, \
- (dev)->link->pmp + (dev)->devno , ##args)
-
-/*
* ata_eh_info helpers
*/
extern void __ata_ehi_push_desc(struct ata_eh_info *ehi, const char *fmt, ...)
--
1.5.2.4
^ permalink raw reply related [flat|nested] 12+ messages in thread