Re: 3.5-rc6 printk formatting problem during oom-kill.

Kay Sievers
2012-07-12T18:26:06Z

On Thu, Jul 12, 2012 at 7:11 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
> On Thu, Jul 12, 2012 at 7:05 AM, Dave Jones <davej@redhat.com> wrote:
>>
>> I've seen it a few times, always with the soft lockup trace.
>
> I bet it's because you have tons of modules, and the line ends up
> being *really* long. And overflows LOG_LINE_MAX. I suspect something
> odd happens.

Straight to the point. That's the issue, combined with the later
safety range checks, we produce somehow "ugly" output.

We already flush the line out of the buffer when we can not add stuff
anymore. The line length is then close to LOG_LINE_MAX, and we want to
add a prefix with the timestamp during output and we reach the limit
of LOG_LINE_MAX.

> There are tons of odd special cases for LOG_LINE_MAX, and I bet Kay
> doesn't see it for the simple reason that he's not totally insane, and
> hasn't loaded hundreds of modules.

Yeah, I just added a loop now that prints over-long continuation
lines, and I can see parts of the effect Dave sees.

> Kay, I suspect the "continuation line" logic could easily have a rule like
>
> "If the old line is already > 80 characters, do a line break here
> and add TAB to the beginning of the new line"
>
> In fact, that could be really nice for things like stack dumps etc -
> we wouldn't have to worry about line breaks and crap, if the printk
> logic just makes "KERN_CONT" do a line break automatically if it
> doesn't fit on the screen.
>
> People who use KERN_CONT don't do it because they *need* things to be
> on one line (it's not guaranteed anyway), they do it because they want
> the output to be dense and readable. Doing auto-line-break would
> actually *help*. And would mean that you never hit the odd
> LOG_LINE_MAX cases just because somebody is printing lots of modules.

That sounds good. I'll look into that.

Kay