[PATCH v2] pstore: Don't use semaphores in always-atomic-context code

[PATCH v2] pstore: Don't use semaphores in always-atomic-context code

[Jann Horn]

pstore_dump() is *always* invoked in atomic context (nowadays in an RCU
read-side critical section, before that under a spinlock).
It doesn't make sense to try to use semaphores here.

This is mostly a revert of commit ea84b580b955 ("pstore: Convert buf_lock
to semaphore"), except that two parts aren't restored back exactly as they
were:

 - keep the lock initialization in pstore_register
 - in efi_pstore_write(), always set the "block" flag to false
 - omit "is_locked", that was unnecessary since
   commit 959217c84c27 ("pstore: Actually give up during locking failure")
 - fix the bailout message

The actual problem that the buggy commit was trying to address may have
been that the use of preemptible() in efi_pstore_write() was wrong - it
only looks at preempt_count() and the state of IRQs, but __rcu_read_lock()
doesn't touch either of those under CONFIG_PREEMPT_RCU.
(Sidenote: CONFIG_PREEMPT_RCU means that the scheduler can preempt tasks in
RCU read-side critical sections, but you're not allowed to actively
block/reschedule.)

Lockdep probably never caught the problem because it's very rare that you
actually hit the contended case, so lockdep always just sees the
down_trylock(), not the down_interruptible(), and so it can't tell that
there's a problem.

Fixes: ea84b580b955 ("pstore: Convert buf_lock to semaphore")
Cc: stable@vger.kernel.org
Acked-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
Signed-off-by: Jann Horn <jannh@google.com>
---
changed in v2:
 - fix incomplete sentence in commit message (Sebastian)
 - make comment in pstore_cannot_block_path() more verbose (Sebastian)
 - add Sebastian's ack

Testing on 5.15.24 (latest stable), with CONFIG_PREEMPT=y, when I trigger
a BUG() via LKDTM ("echo BUG > /sys/kernel/debug/provoke-crash/DIRECT"),
I first get the expected BUG splat, followed by this RCU warning:

Voluntary context switch within RCU read-side critical section!
WARNING: CPU: 2 PID: 1478 at kernel/rcu/tree_plugin.h:316 rcu_note_context_switch+0x525/0x580
Modules linked in:
CPU: 2 PID: 1478 Comm: bash Tainted: G      D           5.15.24jann #90
[...]
RIP: 0010:rcu_note_context_switch+0x525/0x580
Code: 08 4d 89 be 38 03 00 00 49 89 b6 40 03 00 00 48 89 3e e9 42 fd ff ff 48 c7 c7 20 a4 06 92 c6 05 ce f7 a2 01 01 e8 03 fc bc 00 <0f> 0b e9 2b fb ff ff 48 8b 73 20 c6 43 15 00 ba 01 00 00 00 48 8b
RSP: 0018:ffffb27f01f8f910 EFLAGS: 00010082
RAX: 000000000000003f RBX: ffff9f5e8f6abd80 RCX: ffff9f5e8f69b608
RDX: 00000000ffffffd8 RSI: 0000000000000027 RDI: ffff9f5e8f69b600
RBP: 0000000000000000 R08: ffffffff924d5fe8 R09: 0000000000000003
R10: ffffffff92466000 R11: 3fffffffffffffff R12: ffff9f5e8f6ab0c0
R13: ffff9f5be87b3a00 R14: 0000000000000007 R15: 0000000000000400
FS:  00007f998ba3d740(0000) GS:ffff9f5e8f680000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055fa242279b8 CR3: 00000001602f6004 CR4: 00000000001706e0
Call Trace:
 <TASK>
 __schedule+0x74/0x6e0
 schedule+0x59/0xc0
 schedule_timeout+0xf7/0x140
 ? __prepare_to_swait+0x4b/0x70
 wait_for_completion+0x79/0xc0
 virt_efi_query_variable_info+0x141/0x150
 efi_query_variable_store+0x41/0x180
 efivar_entry_set_safe+0xa5/0x1f0
 efi_pstore_write+0xe6/0x130
 pstore_dump+0x177/0x290
 ? lkdtm_BUG+0x5/0x10
 kmsg_dump+0x46/0x60
 oops_end+0x47/0x90
 do_trap+0xcc/0x120
 do_error_trap+0x65/0x80
 ? lkdtm_BUG+0x5/0x10
 exc_invalid_op+0x4e/0x70
 ? lkdtm_BUG+0x5/0x10
 asm_exc_invalid_op+0xf/0x20
RIP: 0010:lkdtm_BUG+0x5/0x10
Code: ef e8 af a3 aa ff 8b 44 24 18 5a 59 48 83 c4 10 5d c3 b8 f4 ff ff ff eb f3 cc cc cc cc cc cc cc cc cc cc cc cc 0f 1f 44 00 00 <0f> 0b 66 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 83 05 38 6b bb 01
RSP: 0018:ffffb27f01f8fe60 EFLAGS: 00010282
RAX: ffffffff91240710 RBX: 0000000000000001 RCX: 0000000000000000
RDX: ffff9f5e8f6a7400 RSI: ffff9f5e8f69b600 RDI: ffffffff91d13550
RBP: ffffffff9218acab R08: ffffffff924d5fe8 R09: 0000000000000003
R10: 00000000fffff000 R11: 3fffffffffffffff R12: ffff9f5be87be000
R13: 0000000000000004 R14: ffffb27f01f8ff10 R15: 0000000000000004
 ? lkdtm_check_bool_cmdline+0x80/0x80
 direct_entry.cold+0x2c/0x37
 full_proxy_write+0x53/0x80
 vfs_write+0xc0/0x280
 ksys_write+0x4f/0xc0
 do_syscall_64+0x3b/0x90
 entry_SYSCALL_64_after_hwframe+0x44/0xae

This patch makes the RCU context warning go away.

 drivers/firmware/efi/efi-pstore.c |  2 +-
 fs/pstore/platform.c              | 39 +++++++++++++++----------------
 include/linux/pstore.h            |  7 +++---
 3 files changed, 24 insertions(+), 24 deletions(-)

diff --git a/drivers/firmware/efi/efi-pstore.c b/drivers/firmware/efi/efi-pstore.c
index 0ef086e43090..7e771c56c13c 100644
--- a/drivers/firmware/efi/efi-pstore.c
+++ b/drivers/firmware/efi/efi-pstore.c
@@ -266,7 +266,7 @@ static int efi_pstore_write(struct pstore_record *record)
 		efi_name[i] = name[i];
 
 	ret = efivar_entry_set_safe(efi_name, vendor, PSTORE_EFI_ATTRIBUTES,
-			      preemptible(), record->size, record->psi->buf);
+			      false, record->size, record->psi->buf);
 
 	if (record->reason == KMSG_DUMP_OOPS && try_module_get(THIS_MODULE))
 		if (!schedule_work(&efivar_work))
diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index f243cb5e6a4f..31d5f9331210 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -143,27 +143,29 @@ static void pstore_timer_kick(void)
 	mod_timer(&pstore_timer, jiffies + msecs_to_jiffies(pstore_update_ms));
 }
 
-/*
- * Should pstore_dump() wait for a concurrent pstore_dump()? If
- * not, the current pstore_dump() will report a failure to dump
- * and return.
- */
-static bool pstore_cannot_wait(enum kmsg_dump_reason reason)
+bool pstore_cannot_block_path(enum kmsg_dump_reason reason)
 {
-	/* In NMI path, pstore shouldn't block regardless of reason. */
+	/*
+	 * In case of NMI path, pstore shouldn't be blocked
+	 * regardless of reason.
+	 */
 	if (in_nmi())
 		return true;
 
 	switch (reason) {
 	/* In panic case, other cpus are stopped by smp_send_stop(). */
 	case KMSG_DUMP_PANIC:
-	/* Emergency restart shouldn't be blocked. */
+	/*
+	 * Emergency restart shouldn't be blocked by spinning on
+	 * pstore_info::buf_lock.
+	 */
 	case KMSG_DUMP_EMERG:
 		return true;
 	default:
 		return false;
 	}
 }
+EXPORT_SYMBOL_GPL(pstore_cannot_block_path);
 
 #if IS_ENABLED(CONFIG_PSTORE_DEFLATE_COMPRESS)
 static int zbufsize_deflate(size_t size)
@@ -389,21 +391,19 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 	unsigned long	total = 0;
 	const char	*why;
 	unsigned int	part = 1;
+	unsigned long	flags = 0;
 	int		ret;
 
 	why = kmsg_dump_reason_str(reason);
 
-	if (down_trylock(&psinfo->buf_lock)) {
-		/* Failed to acquire lock: give up if we cannot wait. */
-		if (pstore_cannot_wait(reason)) {
-			pr_err("dump skipped in %s path: may corrupt error record\n",
-				in_nmi() ? "NMI" : why);
-			return;
-		}
-		if (down_interruptible(&psinfo->buf_lock)) {
-			pr_err("could not grab semaphore?!\n");
+	if (pstore_cannot_block_path(reason)) {
+		if (!spin_trylock_irqsave(&psinfo->buf_lock, flags)) {
+			pr_err("dump skipped in %s path because of concurrent dump\n"
+				       , in_nmi() ? "NMI" : why);
 			return;
 		}
+	} else {
+		spin_lock_irqsave(&psinfo->buf_lock, flags);
 	}
 
 	kmsg_dump_rewind(&iter);
@@ -467,8 +467,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 		total += record.size;
 		part++;
 	}
-
-	up(&psinfo->buf_lock);
+	spin_unlock_irqrestore(&psinfo->buf_lock, flags);
 }
 
 static struct kmsg_dumper pstore_dumper = {
@@ -594,7 +593,7 @@ int pstore_register(struct pstore_info *psi)
 		psi->write_user = pstore_write_user_compat;
 	psinfo = psi;
 	mutex_init(&psinfo->read_mutex);
-	sema_init(&psinfo->buf_lock, 1);
+	spin_lock_init(&psinfo->buf_lock);
 
 	if (psi->flags & PSTORE_FLAGS_DMESG)
 		allocate_buf_for_compression();
diff --git a/include/linux/pstore.h b/include/linux/pstore.h
index eb93a54cff31..e6bd205ddc63 100644
--- a/include/linux/pstore.h
+++ b/include/linux/pstore.h
@@ -14,7 +14,7 @@
 #include <linux/errno.h>
 #include <linux/kmsg_dump.h>
 #include <linux/mutex.h>
-#include <linux/semaphore.h>
+#include <linux/spinlock.h>
 #include <linux/time.h>
 #include <linux/types.h>
 
@@ -87,7 +87,7 @@ struct pstore_record {
  * @owner:	module which is responsible for this backend driver
  * @name:	name of the backend driver
  *
- * @buf_lock:	semaphore to serialize access to @buf
+ * @buf_lock:	spinlock to serialize access to @buf
  * @buf:	preallocated crash dump buffer
  * @bufsize:	size of @buf available for crash dump bytes (must match
  *		smallest number of bytes available for writing to a
@@ -178,7 +178,7 @@ struct pstore_info {
 	struct module	*owner;
 	const char	*name;
 
-	struct semaphore buf_lock;
+	spinlock_t	buf_lock;
 	char		*buf;
 	size_t		bufsize;
 
@@ -205,6 +205,7 @@ struct pstore_info {
 
 extern int pstore_register(struct pstore_info *);
 extern void pstore_unregister(struct pstore_info *);
+extern bool pstore_cannot_block_path(enum kmsg_dump_reason reason);
 
 struct pstore_ftrace_record {
 	unsigned long ip;

base-commit: 83e396641110663d3c7bb25b9bc0c6a750359ecf
-- 
2.35.1.473.g83b2b277ed-goog

Re: [PATCH v2] pstore: Don't use semaphores in always-atomic-context code

[Kees Cook]

On February 18, 2022 10:19:50 AM PST, Jann Horn <jannh@google.com> wrote:
>pstore_dump() is *always* invoked in atomic context (nowadays in an RCU
>read-side critical section, before that under a spinlock).
>It doesn't make sense to try to use semaphores here.

Ah, very nice. Thanks for the analysis!

>[...]
>-static bool pstore_cannot_wait(enum kmsg_dump_reason reason)
>+bool pstore_cannot_block_path(enum kmsg_dump_reason reason)

Why the rename, extern, and EXPORT? This appears to still only have the same single caller?

> [...]
>-			pr_err("dump skipped in %s path: may corrupt error record\n",
>-				in_nmi() ? "NMI" : why);
>-			return;
>-		}
>-		if (down_interruptible(&psinfo->buf_lock)) {
>-			pr_err("could not grab semaphore?!\n");
>+	if (pstore_cannot_block_path(reason)) {
>+		if (!spin_trylock_irqsave(&psinfo->buf_lock, flags)) {
>+			pr_err("dump skipped in %s path because of concurrent dump\n"
>+				       , in_nmi() ? "NMI" : why);

The pr_err had the comma following the format string moved, and the note about corruption removed. Is that no longer accurate?

Otherwise looks good; thank you!

-- 
Kees Cook

Re: [PATCH v2] pstore: Don't use semaphores in always-atomic-context code

[Jann Horn]

On Wed, Feb 23, 2022 at 8:50 AM Kees Cook <keescook@chromium.org> wrote:
> On February 18, 2022 10:19:50 AM PST, Jann Horn <jannh@google.com> wrote:
> >pstore_dump() is *always* invoked in atomic context (nowadays in an RCU
> >read-side critical section, before that under a spinlock).
> >It doesn't make sense to try to use semaphores here.
>
> Ah, very nice. Thanks for the analysis!
>
> >[...]
> >-static bool pstore_cannot_wait(enum kmsg_dump_reason reason)
> >+bool pstore_cannot_block_path(enum kmsg_dump_reason reason)
>
> Why the rename,

That's one of the parts of commit ea84b580b955 that I included in the
revert. "wait" in the name is not accurate, since "wait" in the kernel
normally refers to scheduling away until some condition is fulfilled.
(Though I guess "block" also isn't the best name either... idk.) The
place where we might want to have different behavior depending on
whether we're handling a kernel crash are spinlocks; during a kernel
crash, we shouldn't deadlock on them, but otherwise, AFAIK it's fine
to block on them.

> extern, and EXPORT? This appears to still only have the same single caller?

Also part of the revert. I figured it might make sense to also revert
that part because:

With this commit applied, the EFI code will always take the "nonblock"
path for now, but that's kinda suboptimal; on some platforms the
"blocking" path uses a semaphore, so we really can't take that, but on
x86 it uses a spinlock, which we could block on if we're not oopsing.
We could avoid needlessly losing non-crash dmesg dumps there; I don't
know whether we care about that though.

So I figured that we might want to start adding new callers to this
later on. But if you want, I'll remove that part of the revert and
resend?

> > [...]
> >-                      pr_err("dump skipped in %s path: may corrupt error record\n",
> >-                              in_nmi() ? "NMI" : why);
> >-                      return;
> >-              }
> >-              if (down_interruptible(&psinfo->buf_lock)) {
> >-                      pr_err("could not grab semaphore?!\n");
> >+      if (pstore_cannot_block_path(reason)) {
> >+              if (!spin_trylock_irqsave(&psinfo->buf_lock, flags)) {
> >+                      pr_err("dump skipped in %s path because of concurrent dump\n"
> >+                                     , in_nmi() ? "NMI" : why);
>
> The pr_err had the comma following the format string moved,

Ah, whoops, that was also part of the revert, but I guess I should
have left that part out...

> and the note about corruption removed. Is that no longer accurate?

There should be no more corruption since commit 959217c84c27 ("pstore:
Actually give up during locking failure") - if we're bailing out, we
can't be causing corruption, I believe?

Re: [PATCH v2] pstore: Don't use semaphores in always-atomic-context code

[Kees Cook]

On Wed, Feb 23, 2022 at 06:50:52PM +0100, Jann Horn wrote:
> On Wed, Feb 23, 2022 at 8:50 AM Kees Cook <keescook@chromium.org> wrote:
> > On February 18, 2022 10:19:50 AM PST, Jann Horn <jannh@google.com> wrote:
> > >pstore_dump() is *always* invoked in atomic context (nowadays in an RCU
> > >read-side critical section, before that under a spinlock).
> > >It doesn't make sense to try to use semaphores here.
> >
> > Ah, very nice. Thanks for the analysis!
> >
> > >[...]
> > >-static bool pstore_cannot_wait(enum kmsg_dump_reason reason)
> > >+bool pstore_cannot_block_path(enum kmsg_dump_reason reason)
> >
> > Why the rename,
> 
> That's one of the parts of commit ea84b580b955 that I included in the
> revert. "wait" in the name is not accurate, since "wait" in the kernel
> normally refers to scheduling away until some condition is fulfilled.
> (Though I guess "block" also isn't the best name either... idk.) The
> place where we might want to have different behavior depending on
> whether we're handling a kernel crash are spinlocks; during a kernel
> crash, we shouldn't deadlock on them, but otherwise, AFAIK it's fine
> to block on them.

Gotcha. I'm find to avoid "wait"; I was just curious why it was
changing, but I see now.

> 
> > extern, and EXPORT? This appears to still only have the same single caller?
> 
> Also part of the revert. I figured it might make sense to also revert
> that part because:
> 
> With this commit applied, the EFI code will always take the "nonblock"
> path for now, but that's kinda suboptimal; on some platforms the
> "blocking" path uses a semaphore, so we really can't take that, but on
> x86 it uses a spinlock, which we could block on if we're not oopsing.
> We could avoid needlessly losing non-crash dmesg dumps there; I don't
> know whether we care about that though.
> 
> So I figured that we might want to start adding new callers to this
> later on. But if you want, I'll remove that part of the revert and
> resend?

Yeah, let's just keep this static -- there's no reason to export it.

> 
> > > [...]
> > >-                      pr_err("dump skipped in %s path: may corrupt error record\n",
> > >-                              in_nmi() ? "NMI" : why);
> > >-                      return;
> > >-              }
> > >-              if (down_interruptible(&psinfo->buf_lock)) {
> > >-                      pr_err("could not grab semaphore?!\n");
> > >+      if (pstore_cannot_block_path(reason)) {
> > >+              if (!spin_trylock_irqsave(&psinfo->buf_lock, flags)) {
> > >+                      pr_err("dump skipped in %s path because of concurrent dump\n"
> > >+                                     , in_nmi() ? "NMI" : why);
> >
> > The pr_err had the comma following the format string moved,
> 
> Ah, whoops, that was also part of the revert, but I guess I should
> have left that part out...
> 
> > and the note about corruption removed. Is that no longer accurate?
> 
> There should be no more corruption since commit 959217c84c27 ("pstore:
> Actually give up during locking failure") - if we're bailing out, we
> can't be causing corruption, I believe?

Yeah, agreed. String content change is fine, the weird leading comma I'd
like to do without. :)

Thanks!

-- 
Kees Cook