Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Subject: Re: [PATCH] printk: Add caller information to printk() output.
To:     Petr Mladek <pmladek@suse.com>, Dmitry Vyukov <dvyukov@google.com>
Cc:     Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Andrew Morton <akpm@linux-foundation.org>,
        LKML <linux-kernel@vger.kernel.org>
References: <1543045075-3008-1-git-send-email-penguin-kernel@I-love.SAKURA.ne.jp>
 <20181130154024.ls3mntfdr4zvluub@pathway.suse.cz>
From:   Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
Message-ID: <f224bd68-7394-ff70-cad6-d3fbbb3b5f7d@i-love.sakura.ne.jp>
Date:   Sat, 1 Dec 2018 23:44:37 +0900
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:60.0) Gecko/20100101
 Thunderbird/60.3.2
MIME-Version: 1.0
In-Reply-To: <20181130154024.ls3mntfdr4zvluub@pathway.suse.cz>
Content-Type: text/plain; charset=utf-8
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On 2018/12/01 0:40, Petr Mladek wrote:
>> Some examples for console output:
>>
>>   [    0.293000] [T1] smpboot: CPU0: Intel(R) Core(TM) i5-4440S CPU @ 2.80GHz (family: 0x6, model: 0x3c, stepping: 0x3)
>>   [    0.299733] [T1] Performance Events: Haswell events, core PMU driver.
>>   [    2.813808] [T35] clocksource: Switched to clocksource tsc
>>   [    2.893984] [C0] random: fast init done
>                   ^
> 
> Please, remove the space between the timestamp and the from field.

This space was emitted by print_time(). Do we want to modify print_time()
not to emit this space if the from field is printed?

If we modify print_time(), I think that the leading spaces inserted by "%5lu"
makes little sense, for "%5lu" is too small for systems with uptime >= 1.16 days
and parsers after all cannot assume fixed length for the timestamp field. Then,
we could change from "%5lu.%06lu" to "%lu.%06lu" so that parsers (like /bin/awk)
can get prefix part using white spaces as a delimiter.

If we want to reduce space, do we want to do like

  [0.293000@T1] smpboot: CPU0: Intel(R) Core(TM) i5-4440S CPU @ 2.80GHz (family: 0x6, model: 0x3c, stepping: 0x3)
  [0.299733@T1] Performance Events: Haswell events, core PMU driver.
  [2.813808@T35] clocksource: Switched to clocksource tsc
  [2.893984@C0] random: fast init done

(if printk_time = true) or

  [@T1] smpboot: CPU0: Intel(R) Core(TM) i5-4440S CPU @ 2.80GHz (family: 0x6, model: 0x3c, stepping: 0x3)
  [@T1] Performance Events: Haswell events, core PMU driver.
  [@T35] clocksource: Switched to clocksource tsc
  [@C0] random: fast init done

(if printk_time = false) ?

Dmitry, what format/delimiter is convenient for parsing by syzbot?

>> @@ -1037,6 +1054,9 @@ void log_buf_vmcoreinfo_setup(void)
>>  	VMCOREINFO_OFFSET(printk_log, len);
>>  	VMCOREINFO_OFFSET(printk_log, text_len);
>>  	VMCOREINFO_OFFSET(printk_log, dict_len);
>> +#ifdef CONFIG_PRINTK_FROM
>> +	VMCOREINFO_OFFSET(printk_log, from_id);
>> +#endif
> 
> The crash tool would need to be updated if anyone wanted to read
> the log from the extended structure. Well, it might be done later
> if people start using it more widely.

Since syzbot can utilize output from only normal consoles, I can
keep extended records unmodified for now.

> 
> I think about adding one more filed "u8 version". It would help
> to solve the external compatibility in the long term.

/dev/kmsg format allows adding more fields, but that format did not define
how to tell what fields are there. If fields are conditionally added by
kernel config options, I don't think that "u8 version" field helps.
Unless we add fields unconditionally, we will need to use $name=$value
(where $name and $value must not contain ',' and ';') representation.

> Anyway, I like this feature. It is compatible with /dev/kmsg
> format. dmesg works well. It helps to sort any mixed output
> from both full and continuous lines.

OK, let's refine this approach.