Date:   Mon, 13 Feb 2023 12:02:53 +0100
From:   Peter Zijlstra <peterz@infradead.org>
To:     Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
Cc:     Ingo Molnar <mingo@kernel.org>, Ingo Molnar <mingo@redhat.com>,
        Waiman Long <longman@redhat.com>,
        Will Deacon <will@kernel.org>,
        Boqun Feng <boqun.feng@gmail.com>,
        Andrew Morton <akpm@linux-foundation.org>,
        LKML <linux-kernel@vger.kernel.org>,
        Linus Torvalds <torvalds@linux-foundation.org>
Subject: Re: [PATCH v3] locking/lockdep: add debug_show_all_lock_holders()
Message-ID: <Y+oY3Xd43nNnkDSB@hirez.programming.kicks-ass.net>
References: <ed17797b-e732-0dd0-2b4e-dc293653c0ac@I-love.SAKURA.ne.jp>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <ed17797b-e732-0dd0-2b4e-dc293653c0ac@I-love.SAKURA.ne.jp>
Precedence: bulk

On Thu, Feb 02, 2023 at 10:59:50PM +0900, Tetsuo Handa wrote:
> Currently, check_hung_uninterruptible_tasks() reports details of locks
> held in the system. Also, lockdep_print_held_locks() does not report
> details of locks held by a thread if that thread is in TASK_RUNNING state.
> Several years of experience of debugging without vmcore tells me that
> these limitations have been a barrier for understanding what went wrong
> in syzbot's "INFO: task hung in" reports.
> 
> I initially thought that the cause of "INFO: task hung in" reports is
> due to over-stressing. But I understood that over-stressing is unlikely.
> I now consider that there likely is a deadlock/livelock bug where lockdep
> cannot report as a deadlock when "INFO: task hung in" is reported.
> 
> A typical case is that thread-1 is waiting for something to happen (e.g.
> wait_event_*()) with a lock held. When thread-2 tries to hold that lock
> using e.g. mutex_lock(), check_hung_uninterruptible_tasks() reports that
> thread-2 is hung and thread-1 is holding a lock which thread-2 is trying
> to hold. But currently check_hung_uninterruptible_tasks() cannot report
> the exact location of thread-1 which gives us an important hint for
> understanding why thread-1 is holding that lock for so long period.
> 
> When check_hung_uninterruptible_tasks() reports a thread waiting for a
> lock, it is important to report backtrace of threads which already held
> that lock. Therefore, allow check_hung_uninterruptible_tasks() to report
> the exact location of threads which is holding any lock.
> 
> debug_show_all_lock_holders() skips current thread if the caller is
> holding no lock, for reporting RCU lock taken inside that function is
> generally useless.

> diff --git a/kernel/hung_task.c b/kernel/hung_task.c
> index c71889f3f3fc..5fba784258b7 100644
> --- a/kernel/hung_task.c
> +++ b/kernel/hung_task.c
> @@ -213,7 +213,7 @@ static void check_hung_uninterruptible_tasks(unsigned long timeout)
>   unlock:
>  	rcu_read_unlock();
>  	if (hung_task_show_lock)
> -		debug_show_all_locks();
> +		debug_show_all_lock_holders();
>  
>  	if (hung_task_show_all_bt) {
>  		hung_task_show_all_bt = false;

This being the hung-task detector, which is mostly about sleeping locks.

> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index e3375bc40dad..d9394de09b79 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -32,6 +32,7 @@
>  #include <linux/sched/clock.h>
>  #include <linux/sched/task.h>
>  #include <linux/sched/mm.h>
> +#include <linux/sched/debug.h>
>  #include <linux/delay.h>
>  #include <linux/module.h>
>  #include <linux/proc_fs.h>
> @@ -6511,6 +6512,33 @@ void debug_show_all_locks(void)
>  	pr_warn("=============================================\n\n");
>  }
>  EXPORT_SYMBOL_GPL(debug_show_all_locks);
> +
> +void debug_show_all_lock_holders(void)
> +{
> +	struct task_struct *g, *p;
> +
> +	if (unlikely(!debug_locks)) {
> +		pr_warn("INFO: lockdep is turned off.\n");
> +		return;
> +	}
> +	pr_warn("\nShowing all threads with locks held in the system:\n");
> +
> +	rcu_read_lock();
> +	for_each_process_thread(g, p) {
> +		if (!p->lockdep_depth)
> +			continue;
> +		if (p == current && p->lockdep_depth == 1)
> +			continue;
> +		sched_show_task(p);

And sched_show_task() being an utter piece of crap that will basically
print garbage for anything that's running (it doesn't have much
options).

Should we try and do better? dump_cpu_task() prefers
trigger_single_cpu_backtrace(), which sends an interrupt in order to get
active registers for the CPU.