From: Uladzislau Rezki <urezki@gmail.com>
To: "Paul E. McKenney" <paulmck@kernel.org>
Cc: urezki@gmail.com, rcu@vger.kernel.org
Subject: Re: get_state_synchronize_rcu() at boot time
Date: Fri, 25 Nov 2022 19:33:46 +0100 [thread overview]
Message-ID: <Y4EKihpFpRWysNvZ@pc638.lan> (raw)
In-Reply-To: <20221125160516.GA303456@paulmck-ThinkPad-P17-Gen-1>
> Hello, Uladzislau,
>
> Here is where I placed that probe code and the corresponding output.
> Where should I be placing it instead?
>
> Thanx, Paul
>
> ------------------------------------------------------------------------
>
> diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> index 219b4b516f387..308cbc5e68a64 100644
> --- a/kernel/rcu/tree.c
> +++ b/kernel/rcu/tree.c
> @@ -4546,8 +4546,17 @@ void rcu_scheduler_starting(void)
> local_irq_restore(flags);
>
> // Switch out of early boot mode.
> + pr_err("-> [%d] Invoke synchronize_rcu(): seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> + synchronize_rcu();
> + pr_err("-> [%d] Done. A seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> rcu_scheduler_active = RCU_SCHEDULER_INIT;
> + pr_err("-> [%d] Invoke synchronize_rcu(): seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> + synchronize_rcu();
> + pr_err("-> [%d] Done. A seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> rcu_test_sync_prims();
> + pr_err("-> [%d] Invoke synchronize_rcu(): seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> + synchronize_rcu();
> + pr_err("-> [%d] Done. A seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> }
>
> /*
> @@ -4817,6 +4826,9 @@ void __init rcu_init(void)
>
> kfree_rcu_batch_init();
> rcu_bootup_announce();
> + pr_err("-> [%d] Invoke synchronize_rcu(): seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> + synchronize_rcu();
> + pr_err("-> [%d] Done. A seq number: %lu\n", current->pid, get_state_synchronize_rcu());
> sanitize_kthread_prio();
> rcu_init_geometry();
> rcu_init_one();
> diff --git a/kernel/rcu/update.c b/kernel/rcu/update.c
> index 7b1e183b0eb23..2993be46f81d5 100644
> --- a/kernel/rcu/update.c
> +++ b/kernel/rcu/update.c
> @@ -557,9 +557,12 @@ struct early_boot_kfree_rcu {
> static void early_boot_test_call_rcu(void)
> {
> static struct rcu_head head;
> + int idx;
> static struct rcu_head shead;
> struct early_boot_kfree_rcu *rhp;
>
> + idx = srcu_down_read(&early_srcu);
> + srcu_up_read(&early_srcu, idx);
> call_rcu(&head, test_callback);
> early_srcu_cookie = start_poll_synchronize_srcu(&early_srcu);
> call_srcu(&early_srcu, &shead, test_callback);
>
> ------------------------------------------------------------------------
>
> [ 0.016333] rcu: -> [0] Invoke synchronize_rcu(): seq number: 12
> [ 0.016334] rcu: -> [0] Done. A seq number: 16
> [ 0.114209] rcu: -> [0] Invoke synchronize_rcu(): seq number: 32
> [ 0.114662] rcu: -> [0] Done. A seq number: 36
> [ 0.115191] rcu: -> [0] Invoke synchronize_rcu(): seq number: 36
> [ 0.115684] rcu: -> [0] Done. A seq number: 40
> [ 0.116046] rcu: -> [0] Invoke synchronize_rcu(): seq number: 48
> [ 0.116202] rcu: -> [0] Done. A seq number: 52
Just for a backup:
urezki@pc638:~/data/raid0/coding/linux-rcu.git$ git diff
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
index 76973d716921..dea7dcc6973b 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -3107,6 +3107,18 @@ static void kfree_rcu_work(struct work_struct *work)
}
rcu_lock_release(&rcu_callback_map);
+ {
+ unsigned long seq_a;
+ unsigned long seq_b;
+
+ seq_a = get_state_synchronize_rcu();
+ synchronize_rcu();
+ seq_b = get_state_synchronize_rcu();
+
+ if (seq_a == seq_b)
+ BUG();
+ }
+
raw_spin_lock_irqsave(&krcp->lock, flags);
if (put_cached_bnode(krcp, bkvhead[i]))
bkvhead[i] = NULL;
urezki@pc638:~/data/raid0/coding/linux-rcu.git$ head -10 Makefile
# SPDX-License-Identifier: GPL-2.0
VERSION = 6
PATCHLEVEL = 1
SUBLEVEL = 0
EXTRAVERSION = -rc1
NAME = Hurr durr I'ma ninja sloth
# *DOCUMENTATION*
# To see a list of typical targets execute "make help"
# More info can be located in ./README
urezki@pc638:~/data/raid0/coding/linux-rcu.git
urezki@pc638:~/data/raid0/coding/linux-rcu.git$ ../scripts/rcuscale.sh
tools/testing/selftests/rcutorture/initrd/init already exists, no need to create it
Results directory: /home/urezki/data/raid0/coding/linux-rcu.git/tools/testing/selftests/rcutorture/res/2022.11.25-17.50.32
tools/testing/selftests/rcutorture/bin/kvm.sh --memory 10G --torture rcuscale --allcpus --duration 1 --kconfig CONFIG_NR_CPUS=64 --kconfig CONFIG_RCU_NOCB_CPU=y --kconfig CONFIG_RCU_NOCB_CPU_DEFAULT_ALL=y --kconfig CONFIG_RCU_LAZY=n --bootargs rcuscale.kfree_rcu_test=1 rcuscale.kfree_nthreads=16 rcuscale.holdoff=20 rcuscale.kfree_loops=10000 torture.disable_onoff_at_boot --trust-make
----Start batch 1: Fri 25 Nov 2022 05:50:32 PM CET
TREE 64: Starting build. Fri 25 Nov 2022 05:50:32 PM CET
TREE 64: Waiting for build to complete. Fri 25 Nov 2022 05:50:32 PM CET
TREE 64: Build complete. Fri 25 Nov 2022 05:50:37 PM CET
---- TREE 64: Kernel present. Fri 25 Nov 2022 05:50:37 PM CET
---- Starting kernels. Fri 25 Nov 2022 05:50:37 PM CET
---- All kernel runs complete. Fri 25 Nov 2022 05:54:37 PM CET
---- TREE 64: Build/run results:
--- Fri 25 Nov 2022 05:50:32 PM CET: Starting build, PID 1284995
--- Fri 25 Nov 2022 05:50:37 PM CET: Starting kernel
--- Fri 25 Nov 2022 05:50:37 PM CET: Starting kernel, PID 1291757
QEMU 5.2.0 monitor - type 'help' for more information
(qemu) Monitoring qemu job at pid 1291776 Fri 25 Nov 2022 05:50:47 PM CET
Grace period for qemu job at pid 1291776 Fri 25 Nov 2022 05:51:37 PM CET
WARNING: Assertion failure in /home/urezki/data/raid0/coding/linux-rcu.git/tools/testing/selftests/rcutorture/res/2022.11.25-17.50.32/TREE/console.log TREE
WARNING: Summary: Bugs: 4 Call Traces: 6
urezki@pc638:~/data/raid0/coding/linux-rcu.git$ cat ../scripts/rcuscale.sh
#! /usr/bin/env bash
LOOPS=10
for (( i=0; i<$LOOPS; i++ )); do
tools/testing/selftests/rcutorture/bin/kvm.sh --memory 10G --torture rcuscale --allcpus --duration 1 \
--kconfig CONFIG_NR_CPUS=64 \
--kconfig CONFIG_RCU_NOCB_CPU=y \
--kconfig CONFIG_RCU_NOCB_CPU_DEFAULT_ALL=y \
--kconfig CONFIG_RCU_LAZY=n \
--bootargs "rcuscale.kfree_rcu_test=1 rcuscale.kfree_nthreads=16 rcuscale.holdoff=20 rcuscale.kfree_loops=10000 torture.disable_onoff_at_boot" --trust-make
echo "Done $i"
done
urezki@pc638:~/data/raid0/coding/linux-rcu.git$
[ 0.911180] ------------[ cut here ]------------
[ 0.911747] kernel BUG at kernel/rcu/tree.c:3119!
[ 0.912332] invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
[ 0.912984] CPU: 0 PID: 408 Comm: kworker/0:2 Not tainted 6.1.0-rc1-00098-gcda6ad040ade-dirty #1509
[ 0.913325] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014
[ 0.913325] Workqueue: events kfree_rcu_work
[ 0.913325] RIP: 0010:kfree_rcu_work+0x348/0x350
[ 0.913325] Code: 85 48 ff ff ff 48 89 df e8 65 61 ff ff e9 3b ff ff ff c7 44 24 08 01 00 00 00 49 8b 6d 00 e9 49 fd ff ff 0f 0b e9 e5 fe ff ff <0f> 0b e8 91 5d af 00 90 48 83 ec 40 65 48 8b 04 25 28 00 00 00 48
[ 0.913325] RSP: 0018:ffff9fc680fc3e08 EFLAGS: 00010246
[ 0.913325] RAX: 0000000000000068 RBX: 0000000000000068 RCX: 0000000000000000
[ 0.913325] RDX: 0000000000000000 RSI: 0000000000000287 RDI: ffffffffab32f9f8
[ 0.913325] RBP: ffff8b2a45525000 R08: ffffffffab32ee30 R09: ffffffffab32ee30
[ 0.913325] R10: 0000000000000000 R11: 0000000000000001 R12: ffff8b2a410d5580
[ 0.913325] R13: ffff9fc680fc3e28 R14: ffff8b2a45524000 R15: ffff8b2c34e1bb28
[ 0.913325] FS: 0000000000000000(0000) GS:ffff8b2c34e00000(0000) knlGS:0000000000000000
[ 0.913325] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 0.913325] CR2: ffff8b2c3ffff000 CR3: 000000029aa0c000 CR4: 00000000000006f0
[ 0.913325] Call Trace:
[ 0.913325] <TASK>
[ 0.913325] ? finish_task_switch.isra.0+0x89/0x260
[ 0.913325] process_one_work+0x1b4/0x310
[ 0.913325] worker_thread+0x48/0x3c0
[ 0.913325] ? process_one_work+0x310/0x310
[ 0.913325] kthread+0xe2/0x110
[ 0.913325] ? kthread_complete_and_exit+0x20/0x20
[ 0.913325] ret_from_fork+0x22/0x30
[ 0.913325] </TASK>
[ 0.913325] Modules linked in:
[ 0.930724] calling init_posix_timers+0x0/0x29 @ 1
[ 0.931651] initcall init_posix_timers+0x0/0x29 returned 0 after 2 usecs
[ 0.933036] calling clockevents_init_sysfs+0x0/0xc7 @ 1
[ 0.933179] ------------[ cut here ]------------
[ 0.934353] initcall clockevents_init_sysfs+0x0/0xc7 returned 0 after 406 usecs
[ 0.934812] kernel BUG at kernel/rcu/tree.c:3119!
--
Uladzislau Rezki
next prev parent reply other threads:[~2022-11-25 18:33 UTC|newest]
Thread overview: 6+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-11-25 16:05 get_state_synchronize_rcu() at boot time Paul E. McKenney
2022-11-25 18:33 ` Uladzislau Rezki [this message]
2022-11-25 18:45 ` Paul E. McKenney
2022-11-25 20:17 ` Paul E. McKenney
2022-11-26 1:38 ` Joel Fernandes
2022-11-26 2:25 ` Paul E. McKenney
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=Y4EKihpFpRWysNvZ@pc638.lan \
--to=urezki@gmail.com \
--cc=paulmck@kernel.org \
--cc=rcu@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.