[PATCH] lockdep: Add header and footer to surround warning reports

Tzung-Bi Shih posted 1 patch 2 months, 3 weeks ago
There is a newer version of this series
kernel/locking/lockdep.c | 34 ++++++++++++++++++++++++++++++++++
1 file changed, 34 insertions(+)
[PATCH] lockdep: Add header and footer to surround warning reports
Posted by Tzung-Bi Shih 2 months, 3 weeks ago
Add header and footer to improve log parsing and automated analysis.
This makes lockdep output easier to interpret.

Signed-off-by: Tzung-Bi Shih <tzungbi@kernel.org>
---
 kernel/locking/lockdep.c | 34 ++++++++++++++++++++++++++++++++++
 1 file changed, 34 insertions(+)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 2d4c5bab5af8..af05d30f1545 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -59,6 +59,7 @@
 #include <linux/console.h>
 #include <linux/kasan.h>
 
+#include <asm/bugs.h>
 #include <asm/sections.h>
 
 #include "lockdep_internals.h"
@@ -110,6 +111,11 @@ static __init int kernel_lockdep_sysctls_init(void)
 late_initcall(kernel_lockdep_sysctls_init);
 #endif /* CONFIG_SYSCTL */
 
+static void print_footer(void)
+{
+	pr_warn("---[ end trace %016llx ]---\n", 0ULL);
+}
+
 DEFINE_PER_CPU(unsigned int, lockdep_recursion);
 EXPORT_PER_CPU_SYMBOL_GPL(lockdep_recursion);
 
@@ -1958,6 +1964,7 @@ print_circular_bug_header(struct lock_list *entry, unsigned int depth,
 		return;
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("======================================================\n");
 	pr_warn("WARNING: possible circular locking dependency detected\n");
 	print_kernel_ident();
@@ -2041,6 +2048,7 @@ static noinline void print_circular_bug(struct lock_list *this,
 
 	printk("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -2561,6 +2569,7 @@ print_bad_irq_dependency(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=====================================================\n");
 	pr_warn("WARNING: %s-safe -> %s-unsafe lock order detected\n",
 		irqclass, irqclass);
@@ -2614,6 +2623,7 @@ print_bad_irq_dependency(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 out:
 	nbcon_cpu_emergency_exit();
 }
@@ -3018,6 +3028,7 @@ print_deadlock_bug(struct task_struct *curr, struct held_lock *prev,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("============================================\n");
 	pr_warn("WARNING: possible recursive locking detected\n");
 	print_kernel_ident();
@@ -3039,6 +3050,7 @@ print_deadlock_bug(struct task_struct *curr, struct held_lock *prev,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -3641,6 +3653,7 @@ static void print_collision(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("============================\n");
 	pr_warn("WARNING: chain_key collision\n");
 	print_kernel_ident();
@@ -3656,6 +3669,7 @@ static void print_collision(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -4013,6 +4027,7 @@ print_usage_bug(struct task_struct *curr, struct held_lock *this,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("================================\n");
 	pr_warn("WARNING: inconsistent lock state\n");
 	print_kernel_ident();
@@ -4040,6 +4055,7 @@ print_usage_bug(struct task_struct *curr, struct held_lock *this,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -4079,6 +4095,7 @@ print_irq_inversion_bug(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("========================================================\n");
 	pr_warn("WARNING: possible irq lock inversion dependency detected\n");
 	print_kernel_ident();
@@ -4123,6 +4140,7 @@ print_irq_inversion_bug(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 out:
 	nbcon_cpu_emergency_exit();
 }
@@ -4811,6 +4829,7 @@ print_lock_invalid_wait_context(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=============================\n");
 	pr_warn("[ BUG: Invalid wait context ]\n");
 	print_kernel_ident();
@@ -4828,6 +4847,7 @@ print_lock_invalid_wait_context(struct task_struct *curr,
 
 	pr_warn("stack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 
@@ -5041,6 +5061,7 @@ print_lock_nested_lock_not_held(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("==================================\n");
 	pr_warn("WARNING: Nested lock was not taken\n");
 	print_kernel_ident();
@@ -5060,6 +5081,7 @@ print_lock_nested_lock_not_held(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -5281,6 +5303,7 @@ static void print_unlock_imbalance_bug(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=====================================\n");
 	pr_warn("WARNING: bad unlock balance detected!\n");
 	print_kernel_ident();
@@ -5296,6 +5319,7 @@ static void print_unlock_imbalance_bug(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -6013,6 +6037,7 @@ static void print_lock_contention_bug(struct task_struct *curr,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=================================\n");
 	pr_warn("WARNING: bad contention detected!\n");
 	print_kernel_ident();
@@ -6028,6 +6053,7 @@ static void print_lock_contention_bug(struct task_struct *curr,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -6680,6 +6706,7 @@ print_freed_lock_bug(struct task_struct *curr, const void *mem_from,
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=========================\n");
 	pr_warn("WARNING: held lock freed!\n");
 	print_kernel_ident();
@@ -6691,6 +6718,7 @@ print_freed_lock_bug(struct task_struct *curr, const void *mem_from,
 
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -6742,6 +6770,7 @@ static void print_held_locks_bug(void)
 	nbcon_cpu_emergency_enter();
 
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("====================================\n");
 	pr_warn("WARNING: %s/%d still has locks held!\n",
 	       current->comm, task_pid_nr(current));
@@ -6750,6 +6779,7 @@ static void print_held_locks_bug(void)
 	lockdep_print_held_locks(current);
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 
 	nbcon_cpu_emergency_exit();
 }
@@ -6811,6 +6841,7 @@ asmlinkage __visible void lockdep_sys_exit(void)
 			return;
 		nbcon_cpu_emergency_enter();
 		pr_warn("\n");
+		pr_warn(CUT_HERE);
 		pr_warn("================================================\n");
 		pr_warn("WARNING: lock held when returning to user space!\n");
 		print_kernel_ident();
@@ -6818,6 +6849,7 @@ asmlinkage __visible void lockdep_sys_exit(void)
 		pr_warn("%s/%d is leaving the kernel with locks still held!\n",
 				curr->comm, curr->pid);
 		lockdep_print_held_locks(curr);
+		print_footer();
 		nbcon_cpu_emergency_exit();
 	}
 
@@ -6837,6 +6869,7 @@ void lockdep_rcu_suspicious(const char *file, const int line, const char *s)
 	/* Note: the following can be executed concurrently, so be careful. */
 	nbcon_cpu_emergency_enter();
 	pr_warn("\n");
+	pr_warn(CUT_HERE);
 	pr_warn("=============================\n");
 	pr_warn("WARNING: suspicious RCU usage\n");
 	print_kernel_ident();
@@ -6874,6 +6907,7 @@ void lockdep_rcu_suspicious(const char *file, const int line, const char *s)
 	lockdep_print_held_locks(curr);
 	pr_warn("\nstack backtrace:\n");
 	dump_stack();
+	print_footer();
 	nbcon_cpu_emergency_exit();
 	warn_rcu_exit(rcu);
 }
-- 
2.52.0.rc1.455.g30608eb744-goog
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by kernel test robot 2 months, 3 weeks ago
Hi Tzung-Bi,

kernel test robot noticed the following build errors:

[auto build test ERROR on tip/locking/core]
[also build test ERROR on linus/master v6.18-rc5 next-20251114]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Tzung-Bi-Shih/lockdep-Add-header-and-footer-to-surround-warning-reports/20251114-143903
base:   tip/locking/core
patch link:    https://lore.kernel.org/r/20251114062730.1828416-1-tzungbi%40kernel.org
patch subject: [PATCH] lockdep: Add header and footer to surround warning reports
config: hexagon-randconfig-001-20251115 (https://download.01.org/0day-ci/archive/20251116/202511162152.utadPKg3-lkp@intel.com/config)
compiler: clang version 16.0.6 (https://github.com/llvm/llvm-project 7cbf1a2591520c2491aa35339f227775f4d3adf6)
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20251116/202511162152.utadPKg3-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202511162152.utadPKg3-lkp@intel.com/

All errors (new ones prefixed by >>):

>> kernel/locking/lockdep.c:62:10: fatal error: 'asm/bugs.h' file not found
   #include <asm/bugs.h>
            ^~~~~~~~~~~~
   1 error generated.


vim +62 kernel/locking/lockdep.c

    61	
  > 62	#include <asm/bugs.h>
    63	#include <asm/sections.h>
    64	

-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by Geert Uytterhoeven 2 months, 3 weeks ago
Hi Tzung-Bi,

On Fri, 14 Nov 2025 at 07:35, Tzung-Bi Shih <tzungbi@kernel.org> wrote:
> Add header and footer to improve log parsing and automated analysis.
> This makes lockdep output easier to interpret.
>
> Signed-off-by: Tzung-Bi Shih <tzungbi@kernel.org>

Thanks for your patch!

> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -1958,6 +1964,7 @@ print_circular_bug_header(struct lock_list *entry, unsigned int depth,
>                 return;
>
>         pr_warn("\n");
> +       pr_warn(CUT_HERE);
>         pr_warn("======================================================\n");

I guess you can drop all lines printing a separator made of equal signs,
as CUT_HERE already contains a graphical separator.

>         pr_warn("WARNING: possible circular locking dependency detected\n");
>         print_kernel_ident();

Gr{oetje,eeting}s,

                        Geert

-- 
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by Tzung-Bi Shih 2 months, 3 weeks ago
On Sat, Nov 15, 2025 at 05:36:43PM +0100, Geert Uytterhoeven wrote:
> On Fri, 14 Nov 2025 at 07:35, Tzung-Bi Shih <tzungbi@kernel.org> wrote:
> > --- a/kernel/locking/lockdep.c
> > +++ b/kernel/locking/lockdep.c
> > @@ -1958,6 +1964,7 @@ print_circular_bug_header(struct lock_list *entry, unsigned int depth,
> >                 return;
> >
> >         pr_warn("\n");
> > +       pr_warn(CUT_HERE);
> >         pr_warn("======================================================\n");
> 
> I guess you can drop all lines printing a separator made of equal signs,
> as CUT_HERE already contains a graphical separator.

I'm not sure if we'd like to maintain the "backward compatibility".  I.e.,
if there are already some tools rely on the "====" to parse the report,
should we consider to preserve the equal sign separators?

Happy to receive some more feedback.
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by Waiman Long 2 months, 3 weeks ago
On 11/14/25 1:27 AM, Tzung-Bi Shih wrote:
> Add header and footer to improve log parsing and automated analysis.
> This makes lockdep output easier to interpret.
>
> Signed-off-by: Tzung-Bi Shih <tzungbi@kernel.org>
> ---
>   kernel/locking/lockdep.c | 34 ++++++++++++++++++++++++++++++++++
>   1 file changed, 34 insertions(+)
>
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 2d4c5bab5af8..af05d30f1545 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -59,6 +59,7 @@
>   #include <linux/console.h>
>   #include <linux/kasan.h>
>   
> +#include <asm/bugs.h>

It should be "<asm/bug.h> to fix problem reported by the kernel test robot.

Cheers,
Longman
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by Tzung-Bi Shih 2 months, 3 weeks ago
On Sat, Nov 15, 2025 at 10:55:46AM -0500, Waiman Long wrote:
> On 11/14/25 1:27 AM, Tzung-Bi Shih wrote:
> > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> > index 2d4c5bab5af8..af05d30f1545 100644
> > --- a/kernel/locking/lockdep.c
> > +++ b/kernel/locking/lockdep.c
> > @@ -59,6 +59,7 @@
> >   #include <linux/console.h>
> >   #include <linux/kasan.h>
> > +#include <asm/bugs.h>
> 
> It should be "<asm/bug.h> to fix problem reported by the kernel test robot.

Thanks.  For some reason, my testing environment and compiler didn't warn
about this.  Will fix it in the next version.
Re: [PATCH] lockdep: Add header and footer to surround warning reports
Posted by kernel test robot 2 months, 3 weeks ago
Hi Tzung-Bi,

kernel test robot noticed the following build errors:

[auto build test ERROR on tip/locking/core]
[also build test ERROR on linus/master v6.18-rc5 next-20251114]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Tzung-Bi-Shih/lockdep-Add-header-and-footer-to-surround-warning-reports/20251114-143903
base:   tip/locking/core
patch link:    https://lore.kernel.org/r/20251114062730.1828416-1-tzungbi%40kernel.org
patch subject: [PATCH] lockdep: Add header and footer to surround warning reports
config: arc-randconfig-001-20251115 (https://download.01.org/0day-ci/archive/20251115/202511152337.qCRw3LXm-lkp@intel.com/config)
compiler: arc-linux-gcc (GCC) 13.4.0
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20251115/202511152337.qCRw3LXm-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202511152337.qCRw3LXm-lkp@intel.com/

All errors (new ones prefixed by >>):

>> kernel/locking/lockdep.c:62:10: fatal error: asm/bugs.h: No such file or directory
      62 | #include <asm/bugs.h>
         |          ^~~~~~~~~~~~
   compilation terminated.


vim +62 kernel/locking/lockdep.c

    61	
  > 62	#include <asm/bugs.h>
    63	#include <asm/sections.h>
    64	

-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki