Re: printk: Add process name information to printk() output.

[Petr Mladek]

On Sat 2020-09-05 01:33:12, John Ogness wrote:
> On 2020-09-04, Petr Mladek <pmladek@xxxxxxxx> wrote:
> >>> I am currently playing with support for all three timestamps based
> >>> on https://lore.kernel.org/lkml/20200814101933.574326079@xxxxxxxxxxxxx/
> >>>
> >>> And I got the following idea:
> >>>
> >>> 1. Storing side:
> >>>
> >>>    Create one more ring/array for storing the optional metadata.
> >>>    It might eventually replace dict ring, see below.
> >>>
> >>>    struct struct printk_ext_info {
> >>> 	u64 ts_boot;			/* timestamp from boot clock */
> >>> 	u64 ts_real;			/* timestamp from real clock */
> >>> 	char process[TASK_COMM_LEN];	/* process name */
> >>>    };
> >>>
> >>>    It must be in a separate array so that struct prb_desc stay stable
> >>>    and crashdump tools do not need to be updated so often.
> >>>
> >>>    But the number of these structures must be the same as descriptors.
> >>>    So it might be:
> >>>
> >>>    struct prb_desc_ring {
> >>> 	unsigned int		count_bits;
> >>> 	struct prb_desc		*descs;
> >>> 	struct printk_ext_info  *ext_info
> >>> 	atomic_long_t		head_id;
> >>> 	atomic_long_t		tail_id;
> >>>    };
> >>>
> >>>    One huge advantage is that these extra information would not block
> >>>    pushing lockless printk buffer upstream.
> >>>
> >>>    It might be even possible to get rid of dict ring and just
> >>>    add two more elements into struct printk_ext_info:
> >>>
> >>> 	  char subsystem[16];	/* for SUBSYSTEM= dict value */
> >>> 	  char device[48];	/* for DEVICE= dict value */
> >
> > From my POV, if we support 3 timestamps then they must be stored
> > reliably. And dict ring is out of the game.
> 
> Agreed. I am just trying to think of how to better manage the strings,
> which currently are rare and optional. That is where the dict_ring
> becomes interesting.
> 
> Perhaps we should use both the fixed structs with the variable
> dict_ring. printk_ext_info could look like this:
> 
> struct struct printk_ext_info {
>     u64 ts_boot;
>     u64 ts_real;
>     char *process;
>     char *subsystem;
>     char *device;
> };
> 
> And @process, @subsystem, @device could all point to null-terminated
> trings within the dict_ring. So printk.c code looks something like this:

Yeah, it would be possible. But I would prefer to start with something
simple. We could always make it more complicated when people
complains.

This extra metadata are not currently read by crashdump tools.
It should be much easier to change them at least in the near future.

> The whole point of the dict_ring is that it allows for variable length
> _optional_ data to be stored. If we decide there is no optional data,
> then dict_ring is not needed.

I know but they are currently used only for subsystem and device names.

I tried to find what are the longest subsystem and device names. They
are limited already now by the buffer for formatting the dictionary in
dev_printk_emit():

	char hdr[128];

and create_syslog_header() prints a warning when the buffer is not
enoung:

	dev_WARN(dev, "device/subsystem name too long");

Google has shown only one syscaller report with this error message,
see
https://lore.kernel.org/lkml/001a113a36724a053a0562f93c05@xxxxxxxxxx/


First, dev_WARN() looks like an overhead. Simple printk() should
be enough. Anyway, this type of error is not a reason for panicing
the system.

Second, I believe that limit device name to 48 characters should
work well in practice. Note that it is not clear how many people,
if any, is using the journalctl filtering. And shrinked device name
should be better than missing one.


I personally would prefer to replace the dict ring with the array.
Bot solutions are not fully reliable. But the array is easier
and we would need it for the timestamps, cpu number, and maybe
some other metadata anyway.

We could always add the dict ring back again when there is
a good use for it.

Best Regards,
Petr