[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <1336617045.25027.2.camel@mop>
Date: Thu, 10 May 2012 04:30:45 +0200
From: Kay Sievers <kay@...y.org>
To: Greg Kroah-Hartmann <greg@...ah.com>
Cc: Yinghai Lu <yinghai@...nel.org>, Joe Perches <joe@...ches.com>,
Linus Torvalds <torvalds@...ux-foundation.org>,
Sasha Levin <levinsasha928@...il.com>,
Ingo Molnar <mingo@...nel.org>, linux-kernel@...r.kernel.org
Subject: Re: [PATCH RESEND 1/3] printk: convert byte-buffer to
variable-length record buffer
On Wed, 2012-05-09 at 16:06 -0700, Greg Kroah-Hartmann wrote:
> On Wed, May 09, 2012 at 04:02:40PM -0700, Yinghai Lu wrote:
> > On Wed, May 9, 2012 at 7:37 AM, Kay Sievers <kay@...y.org> wrote:
> > >
> > >> Changing printk semantics and trying to stabilize
> > >> printk message content are bad ideas though.
> > >
> > > Again, nobody talks about content of here.
> >
> > printk_time=1 does not work anymore with this patch on serial console.
>
> Known issue, I think Kay is working on the solution for this right
> now...
Sure, and this seems to work for me.
Thanks,
Kay
From: Kay Sievers <kay@...y.org>
Subject: printk() - restore timestamp printing at console output
The output of the timestamps got lost with the conversion of the
kmsg buffer to records; restore the old behavior.
Document, that CONFIG_PRINTK_TIME now only controls the output of
the timestamps in the syslog() system call and on the console, and
not the recording of the timestamps.
Signed-off-by: Kay Sievers <kay@...y.org>
---
kernel/printk.c | 43 ++++++++++++++++++++++++++-----------------
lib/Kconfig.debug | 16 ++++++++++------
2 files changed, 36 insertions(+), 23 deletions(-)
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -786,6 +786,22 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static size_t prepend_timestamp(unsigned long long t, char *buf)
+{
+ unsigned long rem_ns;
+
+ if (!printk_time)
+ return 0;
+
+ if (!buf)
+ return 15;
+
+ rem_ns = do_div(t, 1000000000);
+
+ return sprintf(buf, "[%5lu.%06lu] ",
+ (unsigned long) t, rem_ns / 1000);
+}
+
static int syslog_print_line(u32 idx, char *text, size_t size)
{
struct log *msg;
@@ -800,9 +816,7 @@ static int syslog_print_line(u32 idx, ch
len++;
if (msg->level > 99)
len++;
-
- if (printk_time)
- len += 15;
+ len += prepend_timestamp(0, NULL);
len += msg->text_len;
len++;
@@ -810,15 +824,7 @@ static int syslog_print_line(u32 idx, ch
}
len = sprintf(text, "<%u>", msg->level);
-
- if (printk_time) {
- unsigned long long t = msg->ts_nsec;
- unsigned long rem_ns = do_div(t, 1000000000);
-
- len += sprintf(text + len, "[%5lu.%06lu] ",
- (unsigned long) t, rem_ns / 1000);
- }
-
+ len += prepend_timestamp(msg->ts_nsec, text + len);
if (len + msg->text_len > size)
return -EINVAL;
memcpy(text + len, log_text(msg), msg->text_len);
@@ -1741,7 +1747,7 @@ again:
for (;;) {
struct log *msg;
static char text[LOG_LINE_MAX];
- size_t len;
+ size_t len, l;
int level;
raw_spin_lock_irqsave(&logbuf_lock, flags);
@@ -1761,10 +1767,13 @@ again:
msg = log_from_idx(console_idx);
level = msg->level & 7;
- len = msg->text_len;
- if (len+1 >= sizeof(text))
- len = sizeof(text)-1;
- memcpy(text, log_text(msg), len);
+
+ len = prepend_timestamp(msg->ts_nsec, text);
+ l = msg->text_len;
+ if (len + l + 1 >= sizeof(text))
+ l = sizeof(text) - len - 1;
+ memcpy(text + len, log_text(msg), l);
+ len += l;
text[len++] = '\n';
console_idx = log_next(console_idx);
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -3,12 +3,16 @@ config PRINTK_TIME
bool "Show timing information on printks"
depends on PRINTK
help
- Selecting this option causes timing information to be
- included in printk output. This allows you to measure
- the interval between kernel operations, including bootup
- operations. This is useful for identifying long delays
- in kernel startup. Or add printk.time=1 at boot-time.
- See Documentation/kernel-parameters.txt
+ Selecting this option causes time stamps of the printk()
+ messages to be added to the output of the syslog() system
+ call and at the console.
+
+ The timestamp is always recorded internally, and exported
+ to /dev/kmsg. This flag just specifies if the timestamp should
+ be included, not that the timestamp is recorded.
+
+ The behavior is also controlled by the kernel command line
+ parameter printk.time=1. See Documentation/kernel-parameters.txt
config DEFAULT_MESSAGE_LOGLEVEL
int "Default message log level (1-7)"
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists