linux-kernel - Re: [PATCH] kernel/hung_task.c: Use continuously blocked time when reporting.

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] [day] [month] [year] [list]

Message-Id: <20190226134825.a8be172f694eafb7b7f94695@linux-foundation.org>
Date:   Tue, 26 Feb 2019 13:48:25 -0800
From:   Andrew Morton <akpm@...ux-foundation.org>
To:     Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>
Cc:     Dmitry Vyukov <dvyukov@...gle.com>,
        "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        Peter Zijlstra <a.p.zijlstra@...llo.nl>,
        Ingo Molnar <mingo@...e.hu>, linux-kernel@...r.kernel.org
Subject: Re: [PATCH] kernel/hung_task.c: Use continuously blocked time when
 reporting.

On Tue, 26 Feb 2019 18:58:03 +0900 Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp> wrote:

> Since commit a2e514453861dd39 ("kernel/hung_task.c: allow to set checking
> interval separately from timeout") added hung_task_check_interval_secs,
> setting a value different from hung_task_timeout_secs
> 
>   echo 0 > /proc/sys/kernel/hung_task_panic
>   echo 120 > /proc/sys/kernel/hung_task_timeout_secs
>   echo 5 > /proc/sys/kernel/hung_task_check_interval_secs
> 
> causes confusing output as if the task was blocked for
> hung_task_timeout_secs seconds from the previous report.
> 
>   [  399.395930] INFO: task kswapd0:75 blocked for more than 120 seconds.
>   [  405.027637] INFO: task kswapd0:75 blocked for more than 120 seconds.
>   [  410.659725] INFO: task kswapd0:75 blocked for more than 120 seconds.
>   [  416.292860] INFO: task kswapd0:75 blocked for more than 120 seconds.
>   [  421.932305] INFO: task kswapd0:75 blocked for more than 120 seconds.
> 
> Although we could update t->last_switch_time after sched_show_task(t) if
> we want to report only every 120 seconds, reporting every 5 seconds might
> not be very bad for monitoring after a problematic situation has started.
> Thus, let's use continuously blocked time instead of updating previously
> reported time.
> 
>   [  677.985011] INFO: task kswapd0:80 blocked for more than 122 seconds.
>   [  693.856126] INFO: task kswapd0:80 blocked for more than 138 seconds.
>   [  709.728075] INFO: task kswapd0:80 blocked for more than 154 seconds.
>   [  725.600018] INFO: task kswapd0:80 blocked for more than 170 seconds.
>   [  741.473133] INFO: task kswapd0:80 blocked for more than 186 seconds.

hm, maybe.

The user asked for a report if a task was blocked for more than 120
seconds, so the kernel is accurately reporting that this happened.  The
actual blockage time is presumably useful information, but that's a
different thing.

We could report both:

"blocked for 122 seconds which is more than 120 seconds"

But on the other hand, what is the point in telling the user how they
configured their own kernel?

I think I'll stop arguing with myself and apply the patch ;)