lkml.org 
[lkml]   [2018]   [Mar]   [19]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
SubjectRe: [PATCH 1/2] sched/debug: fix per-task line continuation for console
From
Date
On 03/19/2018 04:17 PM, Peter Zijlstra wrote:
> On Mon, Mar 19, 2018 at 02:35:54PM -0400, Joe Lawrence wrote:
>> When the SEQ_printf() macro prints to the console, it runs a simple
>> printk() without KERN_CONT "continued" line printing. The result of
>> this is oddly wrapped task info, for example:
>>
>> % echo t > /proc/sysrq-trigger
>> % dmesg
>> ...
>> runnable tasks:
>> ...
>> [ 29.608611] I
>> [ 29.608613] rcu_sched 8 3252.013846 4087 120
>> [ 29.608614] 0.000000 29.090111 0.000000
>> [ 29.608615] 0 0
>> [ 29.608616] /
>>
>> Modify SEQ_printf to use pr_cont() for expected one-line results:
>>
>> % echo t > /proc/sysrq-trigger
>> % dmesg
>> ...
>> runnable tasks:
>> ...
>> [ 106.716329] S cpuhp/5 37 2006.315026 14 120 0.000000 0.496893 0.000000 0 0 /
>>
>> Signed-off-by: Joe Lawrence <joe.lawrence@redhat.com>
>> ---
>> kernel/sched/debug.c | 2 +-
>> 1 file changed, 1 insertion(+), 1 deletion(-)
>>
>> diff --git a/kernel/sched/debug.c b/kernel/sched/debug.c
>> index 1ca0130ed4f9..50026aa2d81e 100644
>> --- a/kernel/sched/debug.c
>> +++ b/kernel/sched/debug.c
>> @@ -32,7 +32,7 @@
>> if (m) \
>> seq_printf(m, x); \
>> else \
>> - printk(x); \
>> + pr_cont(x); \
>
> That used to work I think.. I think someone changed how printk() behaves
> somewhere along the lines.
>

Hi Peter,

This code:

printk("printk one");
printk("printk two\n");

pr_cont("\n");
pr_cont("pr_cont one");
pr_cont("pr_cont two\n");

pr_cont("pr_cont first line\n");
pr_cont("\n");
pr_cont("\n");
pr_cont("pr_cont next line");

Creates this output:

% uname -r
4.16.0-rc5+

% dmesg
[ 575.221280] printk one
[ 575.221281] printk two
[ 575.221282] pr_cont onepr_cont two
[ 575.221283] pr_cont first line

I don't have the commit offhand that changed the printk behavior, but
from observation:

1 - printk implies a trailing newline:
https://lwn.net/Articles/732420/

2 - pr_cont seems to eat redundant newlines

> Does pr_cont("\n") DTRT? it seems like something weird.
>

Yeah, pr_cont() is kind of a hack. It will terminate a line if that's
the first newline, but as demonstrated above, I don't think it likes
extra newline chars.

A better fix would be to marshal the text into temp buffer then dump it
out. Dunno if you prefer that kind of churn for these stats.

-- Joe

\
 
 \ /
  Last update: 2018-03-19 21:44    [W:0.082 / U:0.068 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site