On Thu, Apr 24, 2014 at 03:40:24PM -0400, Jörn Engel wrote:
> On Wed, 23 April 2014 20:52:47 -0400, Jörn Engel wrote:
> > 
> > I use the patch below for some time now.  While it doesn't avoid the
> > log pollution in the first place, it lessens the impact somewhat.
> 
> Added a config option and ported it to current -linus.  Andrew, would
> you take this patch?
> 
> ---
> 
> Sometimes the printk log is heavily interleaving between different cpus.
> This is particularly bad when you have two backtraces at the same time,
> but can be annoying in other cases as well.  With an explicit cpu
> number, a simple grep can disentangle the mess for you.
> 
> Signed-off-by: Joern Engel <jo...@logfs.org>
> ---
>  kernel/printk/printk.c | 19 ++++++++++++++++---
>  lib/Kconfig.debug      |  9 +++++++++
>  2 files changed, 25 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index a45b50962295..b9e464924825 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -200,6 +200,7 @@ struct printk_log {
>       u16 len;                /* length of entire record */
>       u16 text_len;           /* length of text buffer */
>       u16 dict_len;           /* length of dictionary buffer */
> +     u16 cpu;                /* cpu the message was generated on */
>       u8 facility;            /* syslog facility */
>       u8 flags:5;             /* internal record flags */
>       u8 level:3;             /* syslog level */
> @@ -346,6 +347,7 @@ static void log_store(int facility, int level,
>       msg->facility = facility;
>       msg->level = level & 7;
>       msg->flags = flags & 0x1f;
> +     msg->cpu = smp_processor_id();
>       if (ts_nsec > 0)
>               msg->ts_nsec = ts_nsec;
>       else
> @@ -859,7 +861,7 @@ static bool printk_time;
>  #endif
>  module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
>  
> -static size_t print_time(u64 ts, char *buf)
> +static size_t print_time(u64 ts, u16 cpu, char *buf)
>  {
>       unsigned long rem_nsec;
>  
> @@ -868,11 +870,20 @@ static size_t print_time(u64 ts, char *buf)
>  
>       rem_nsec = do_div(ts, 1000000000);
>  
> +#ifdef CONFIG_PRINTK_CPU
> +     if (!buf)
> +             return snprintf(NULL, 0, "[%5lu.000000,%02x] ",

%02x for a cpu?  What happens on machines with 8k cpus?

And is this really an issue?  Debugging by using printk is fun, but not
really something that people need to add a cpu number to.  Why not just
use a tracepoint in your code to get the needed information instead?

thanks,

greg k-h
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Reply via email to