linux-kernel - Re: WARNING: CPU: 1 PID: 14735 at fs/dcache.c:365 dentry

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]

Date:   Wed, 20 Jul 2022 11:21:51 +0200
From:   Helge Deller <deller@....de>
To:     Al Viro <viro@...iv.linux.org.uk>
Cc:     Helge Deller <deller@....de>, Hillf Danton <hdanton@...a.com>,
        linux-kernel@...r.kernel.org, linux-parisc@...r.kernel.org
Subject: Re: WARNING: CPU: 1 PID: 14735 at fs/dcache.c:365
 dentry_free+0x100/0x128

* Al Viro <viro@...iv.linux.org.uk>:
> On Wed, Jul 20, 2022 at 08:53:53AM +0200, Helge Deller wrote:
> > On 7/20/22 05:29, Al Viro wrote:
> > > On Sat, Jul 16, 2022 at 07:27:30AM +0200, Helge Deller wrote:
> > >> On 7/15/22 15:33, Hillf Danton wrote:
> > >
> > >> [108565.341434] dentry->d_u.d_rcu = 0x416be770
> > >
> > > Incidentally, does that match the address of __d_free() on your build,
> > > or is it something different?
> >
> > I don't think it's __d_free().
> > The source is:
> > 	pr_err("dentry->d_u.d_rcu = %pS\n", dentry->d_u.d_rcu.func);
> > so the "%pS" would probably have resolved the pointer to string "__d_free" (or something else).
>
> ????
>
> That should've taken a word from desc->addr and printed it.
> If it had managed to get to a string (you'd needed to have
> CONFIG_KALLSYMS enabled), it would've printed it as a string,
> not as hex address.  Seriously, check System.map for that
> kernel...

CONFIG_KALLSYMS is enabled - otherwise I wouldn't see the backtrace either
(just to be sure I did check the .config again).
But it might be, that when I produced that debug info I had
%p instead of %pS - that might explain why the function name wasn't resolved.

The kernel functions on my build on parisc range from
0000000040100000 T __init_begin
to
0000000041700000 D _end

In my current System.map (which may not fit the address above!) I see:
00000000416bda50 d in_lookup_hashtable
00000000416bfa50 d counter.0
so,   0x416be770 would be in in_lookup_hashtable(). Does that make sense?
Again - this is a somewhat newer build...

Btw, you asked if there were any other private discussions/mails on other mailing lists:
There are none, only those which are in this mail thread.

Below is the current patch with which I will try to reproduce the issue.
I'll disable hashed pointers too.
Any other info/patches I should add?

Reproducing it is time-consuming. It takes me usually a day to trigger.

Helge


diff --git a/fs/dcache.c b/fs/dcache.c
index 93f4f5ee07bf..047729fc1a97 100644
--- a/fs/dcache.c
+++ b/fs/dcache.c
@@ -360,11 +360,32 @@ static inline void __d_clear_type_and_inode(struct dentry *dentry)
 		this_cpu_inc(nr_dentry_negative);
 }

+static void show_dentry_info(struct dentry *dentry)
+{
+	pr_err("dentry = %px\n", dentry);
+	pr_err("spin_is_locked(&dentry->d_lock) = %d\n", spin_is_locked(&dentry->d_lock));
+	pr_err("dname_external(dentry) = %d\n", dname_external(dentry));
+	pr_err("dentry->d_flags = 0x%x\n", dentry->d_flags);
+	// pr_err("ERROR on file %pd\n", &dentry); HANGS
+	pr_err("dentry->d_name.len = %d\n", dentry->d_name.len);
+	pr_err("dentry->d_name.hash = 0x%x\n", dentry->d_name.hash);
+	pr_err("dentry->d_lockref.count = %d\n", dentry->d_lockref.count);
+	pr_err("dentry->d_flags = 0x%x\n", dentry->d_flags);
+	pr_err("dentry->d_inode = %px\n", dentry->d_inode);
+	pr_err("dentry->d_parent = %px\n", dentry->d_parent);
+	pr_err("dentry->d_u.d_rcu = %pS\n", dentry->d_u.d_rcu.func);
+}
+
 static void dentry_free(struct dentry *dentry)
 {
-	WARN_ON(!hlist_unhashed(&dentry->d_u.d_alias));
+	int unhashed = hlist_unhashed(&dentry->d_u.d_alias);
+	if (WARN_ON(!unhashed)) {
+		show_dentry_info(dentry);
+	}
 	if (unlikely(dname_external(dentry))) {
 		struct external_name *p = external_name(dentry);
+		if (!unhashed)
+			pr_err("value of &p->u.count = %d\n", p->u.count.counter);
 		if (likely(atomic_dec_and_test(&p->u.count))) {
 			call_rcu(&dentry->d_u.d_rcu, __d_free_external);
 			return;
@@ -605,8 +626,13 @@ static void __dentry_kill(struct dentry *dentry)
 		spin_unlock(&parent->d_lock);
 	if (dentry->d_inode)
 		dentry_unlink_inode(dentry);
-	else
+	else {
+		if (WARN_ON_ONCE(d_in_lookup(dentry))) {
+			show_dentry_info(dentry);
+			__d_lookup_done(dentry);
+		}
 		spin_unlock(&dentry->d_lock);
+	}
 	this_cpu_dec(nr_dentry);
 	if (dentry->d_op && dentry->d_op->d_release)
 		dentry->d_op->d_release(dentry);
@@ -616,6 +642,8 @@ static void __dentry_kill(struct dentry *dentry)
 		dentry->d_flags |= DCACHE_MAY_FREE;
 		can_free = false;
 	}
+	if (WARN_ON(!hlist_unhashed(&dentry->d_u.d_alias)))
+		show_dentry_info(dentry);
 	spin_unlock(&dentry->d_lock);
 	if (likely(can_free))
 		dentry_free(dentry);