linux-kernel - Re: [PATCH 3/3] printk: using booting time as the timestamp

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [day] [month] [year] [list]

Message-ID: <20140405080119.GA11096@twins.programming.kicks-ass.net>
Date:	Sat, 5 Apr 2014 10:01:19 +0200
From:	Peter Zijlstra <peterz@...radead.org>
To:	John Stultz <john.stultz@...aro.org>
Cc:	Lei Wen <leiwen@...vell.com>, Thomas Gleixner <tglx@...utronix.de>,
	Stephen Boyd <sboyd@...eaurora.org>,
	Andrew Morton <akpm@...ux-foundation.org>,
	Steven Rostedt <rostedt@...dmis.org>,
	Michael Opdenacker <michael.opdenacker@...e-electrons.com>,
	Joe Perches <joe@...ches.com>, Tejun Heo <tj@...nel.org>,
	Petr Mladek <pmladek@...e.cz>, linux-kernel@...r.kernel.org
Subject: Re: [PATCH 3/3] printk: using booting time as the timestamp

On Fri, Apr 04, 2014 at 02:55:35PM -0700, John Stultz wrote:
> On 04/03/2014 08:18 PM, Lei Wen wrote:
> > As people may want to align the kernel log with some other processor
> > running over the same machine but not the same copy of linux, we
> > need to keep their log aligned, so that it would not make debug
> > process hard and confused.
> >
> > Signed-off-by: Lei Wen <leiwen@...vell.com>
> > ---
> >  kernel/printk/printk.c | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> >
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index a45b509..af96fbd 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -349,7 +349,7 @@ static void log_store(int facility, int level,
> >  	if (ts_nsec > 0)
> >  		msg->ts_nsec = ts_nsec;
> >  	else
> > -		msg->ts_nsec = local_clock();
> > +		msg->ts_nsec = ktime_to_ns(ktime_get_boottime());
> 
> No no... Since ktime_get_boottime() takes the timekeeping seqlock, this
> will cause any printk (or WARN_ON, etc) that is done while holding a
> write in the timekeeping seqlock to deadlock (which I mentioned last time).
> 
> I think the better solution here is to have the timekeeping code provide
> the printk logic the offset value whenever the sleep time is updated.
> That way the printk logic can manage its own values w/o having to take
> any timekeeping locks.
> 
> That said, I'm still not really fond of trying to add this
> functionality. The printk timestamping code was always a little fuzzy,
> using jiffies or sched_clock in order to give a rough estimate of boot
> delays (and didn't include ntp freq correction, etc). When it was
> introduced, I feel like folks were concerned about this, but folks
> agreed the rough estimates were worth it, and it didn't have to involve
> the real timekeeping code.  Now, trying to raise the bar here to make
> printk timestamps actually correlate with
> CLOCK_BOOTTIME/REALTIME/MONOTONIC (which I'll admit, seems quite
> reasonable given we have timestamps already - but ends up being feature
> creep) will add quite a bit of complexity due to the fact that printk is
> supposed to be safe to call from everywhere.
> 
> And again, syslog can add timestamps to the kernel messages relatively
> well in userland. So I'm not sure the need is clear.

Not to mention that ktime_get*() is stupid slow for some.
--
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/