Re: Re: [RFC PATCH 1/2] printk: Add context information to the header of /dev/kmsg

[Yoshihiro YUNOMAE]

Hi Kay,

Thank you for your reply.

(2014/05/19 20:35), Kay Sievers wrote:
> On Mon, May 19, 2014 at 7:28 PM, Yoshihiro YUNOMAE
> <yoshihiro.yunomae.ez@xxxxxxxxxxx> wrote:
> > Add context information to the header of /dev/kmsg.
> >
> > Two printk messages connected with KERN_CONT can be divided in multiple lines
> > by a different process context message. If the different context message seems
> > like the 1st divided message, it is difficult to understand which the 2nd
> > divided message belongs to. This problem can also occur for the situation where
> > multiple message lines without KERN_CONT are broken into by similar messages.
> > For example, SCSI disk error messages can be show as follows:
> >
> >          [110781.736171] sd 2:0:0:0: [sdb]
> >          [110781.736170] sd 3:0:0:0: [sdc] Unhandled sense code
> >          [110781.736172] sd 3:0:0:0: [sdc]
> >          [110781.736175] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
> >          [110781.736177] sd 3:0:0:0: [sdc]
> >          [110781.736178] Sense Key : Medium Error [current]
> >          [110781.736187] Sense Key : Recovered Error
> >          [110781.736189] [current]
>
> [...]
>
> > This patch adds PID and interrupt context flag to the header of /dev/kmsg as
> > the context information in order to understand relation of output messages. If
> > PID values of two messages and the interrupt context flags are same, it means
> > that those messages are same context, so those message have some relation. If
> > not so, it means that those messages are different context, so users do not
> > need to take care about the relation of the messages.
>
> [...]
>
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -197,6 +197,8 @@ enum log_flags {
> >
> >   struct printk_log {
> >          u64 ts_nsec;            /* timestamp in nanoseconds */
> > +       pid_t pid;              /* identify PID */
> > +       u32 irq_count;          /* identify irq_count */
>
> I don't think it is worth to blow-up this heavily used struct up even
> more, just because SCSI cannot log in simple single calls. How about
> fixing SCSI to log to a local buffer if it cannot safely print one
> line at once.
>
> I'm not convinced, that turning the /dev/kmsg format into an
> "annotation language', and requiring a rather complex state machine to
> re-construct the "broken" logging makes too much sense here. If tools
> rely on properly formatted logging messages, the logging should be
> fixed at the source while it is logged, not be reconstructed later.
>
> It is not not my call, but I don't this makes much sense. Continuation
> lines are "best effort" not a facility that is or ever was reliable in
> the past. I think the proper fix is how the log is created, not how it
> is exported.

As we discussed about this issue in LinuxCon Japan, mixed messages will
be fixed in each subsystem. In the SCSI layer, tracing feature will be
used. (http://www.spinics.net/lists/linux-scsi/msg74428.html)
If we found the same issue in other subsystem, we would like to add
new generic printk API to avoid mixed messages.

Thank you,
Yoshihiro YUNOMAE

--
Yoshihiro YUNOMAE
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: yoshihiro.yunomae.ez@xxxxxxxxxxx


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