linux-kernel - Re: [RFC][PATCHv6 00/12] printk: introduce printing kernel thread

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Tue, 19 Dec 2017 10:24:55 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        Petr Mladek <pmladek@...e.com>, Tejun Heo <tj@...nel.org>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Jan Kara <jack@...e.cz>,
        Andrew Morton <akpm@...ux-foundation.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Rafael Wysocki <rjw@...ysocki.net>,
        Pavel Machek <pavel@....cz>,
        Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>,
        linux-kernel@...r.kernel.org
Subject: Re: [RFC][PATCHv6 00/12] printk: introduce printing kernel thread

On (12/18/17 20:08), Steven Rostedt wrote:
> > ... do you guys read my emails? which part of the traces I have provided
> > suggests that there is any improvement?
> 
> The traces I've seen from you were from non-realistic scenarios.
> But I have hit issues with printk()s happening that cause one CPU to do all
> the work, where my patch would fix that. Those are the scenarios I'm
> talking about.

any hints about what makes your scenario more realistic than mine?
to begin with, what was the scenario?

[..]

> But I have hit issues with printk()s happening that cause one CPU to do all
> the work, where my patch would fix that. Those are the scenarios I'm
> talking about.

and this is exactly what I'm still observing. i_do_printks-1992 stops
printing, while console_sem is owned by another task. Since log_store()
much faster than call_console_drivers() AND console_sem owner is getting
preempted for unknown period of time, we end up having pending messages
in logbuf... and it's kworker/0:1-135 that prints them all.

   systemd-udevd-671   [003] d..3    66.334866: offloading: set console_owner
     kworker/0:1-135   [000] d..2    66.335999: offloading: vprintk_emit()->trylock FAIL  will spin? :1
    i_do_printks-1992  [002] d..2    66.345474: offloading: vprintk_emit()->trylock FAIL  will spin? :0    x 1100
   ...
   systemd-udevd-671   [003] d..3    66.345917: offloading: clear console_owner  waiter != NULL :1

	-ss