* modprobe rbtree-test nnodes=1000 gets soft lockup
@ 2020-07-03 21:15 jim.cromie
0 siblings, 0 replies; only message in thread
From: jim.cromie @ 2020-07-03 21:15 UTC (permalink / raw)
To: kernelnewbies
hey fellow noobs/readers
modprobe rbtree-test nnodes=1000 gets soft lockup
timing seems semi-quadratic
large sets seem to knock it over,
I cut perf_loops in 1/10, expecting that to fix it,
it didnt.
does anyone else see this ?
bash-5.0# modprobe rbtree_test
[ 17.808044][ T233] rbtree testing
[ 17.817992][ T233] -> test 1 (latency of nnodes insert+delete):
25770 cycles
[ 17.829363][ T233] -> test 2 (latency of nnodes cached
insert+delete): 25066 cycles
[ 17.831705][ T233] -> test 3 (latency of inorder traversal): 2333 cycles
[ 17.832994][ T233] -> test 4 (latency to fetch first node)
[ 17.833931][ T233] non-cached: 21 cycles
[ 17.834756][ T233] cached: 13 cycles
[ 17.910160][ T233] augmented rbtree testing
[ 17.931726][ T233] -> test 1 (latency of nnodes insert+delete):
55888 cycles
[ 17.954803][ T233] -> test 2 (latency of nnodes cached
insert+delete): 54948 cycles
[ 18.052785][ T233] dynamic_debug:ddebug_remove_module: removing
module "rbtree_test"
modprobe: ERROR: could not insert 'rbtree_test': Resource temporarily
unavailable
bash-5.0# modprobe rbtree_test nnodes=500
[ 33.843314][ T235] rbtree testing
[ 33.919317][ T235] -> test 1 (latency of nnodes insert+delete):
196957 cycles
[ 34.002251][ T235] -> test 2 (latency of nnodes cached
insert+delete): 209320 cycles
[ 34.008807][ T235] -> test 3 (latency of inorder traversal): 12848 cycles
[ 34.010039][ T235] -> test 4 (latency to fetch first node)
[ 34.011065][ T235] non-cached: 24 cycles
[ 34.011795][ T235] cached: 13 cycles
[ 35.955906][ T235] augmented rbtree testing
[ 36.099845][ T235] -> test 1 (latency of nnodes insert+delete):
373062 cycles
[ 36.246031][ T235] -> test 2 (latency of nnodes cached
insert+delete): 372324 cycles
[ 38.821936][ T235] dynamic_debug:ddebug_remove_module: removing
module "rbtree_test"
modprobe: ERROR: could not insert 'rbtree_test': Resource temporarily
unavailable
bash-5.0# modprobe rbtree_test nnodes=1000
[ 46.987262][ T237] rbtree testing
[ 47.157653][ T237] -> test 1 (latency of nnodes insert+delete):
441603 cycles
[ 47.342749][ T237] -> test 2 (latency of nnodes cached
insert+delete): 475413 cycles
[ 47.355668][ T237] -> test 3 (latency of inorder traversal): 29168 cycles
[ 47.356965][ T237] -> test 4 (latency to fetch first node)
[ 47.357917][ T237] non-cached: 36 cycles
[ 47.358638][ T237] cached: 13 cycles
[ 55.581422][ T237] augmented rbtree testing
[ 55.891384][ T237] -> test 1 (latency of nnodes insert+delete):
803375 cycles
[ 56.200665][ T237] -> test 2 (latency of nnodes cached
insert+delete): 796702 cycles
[ 66.887909][ T237] dynamic_debug:ddebug_remove_module: removing
module "rbtree_test"
modprobe: ERROR: could not insert 'rbtree_test': Resource temporarily
unavailable
bash-5.0# modprobe rbtree_test nnodes=1500
[ 81.481918][ T239] rbtree testing
[ 81.763810][ T239] -> test 1 (latency of nnodes insert+delete):
730506 cycles
[ 82.066386][ T239] -> test 2 (latency of nnodes cached
insert+delete): 778610 cycles
[ 82.086648][ T239] -> test 3 (latency of inorder traversal): 48465 cycles
[ 82.087706][ T239] -> test 4 (latency to fetch first node)
[ 82.088728][ T239] non-cached: 61 cycles
[ 82.089511][ T239] cached: 13 cycles
[ 101.149656][ T239] augmented rbtree testing
[ 101.622513][ T239] -> test 1 (latency of nnodes insert+delete):
1225584 cycles
[ 102.112011][ T239] -> test 2 (latency of nnodes cached
insert+delete): 1263990 cycles
[ 127.491941][ T239] dynamic_debug:ddebug_remove_module: removing
module "rbtree_test"
modprobe: ERROR: could not insert 'rbtree_test': Resource temporarily
unavailable
bash-5.0# modprobe rbtree_test nnodes=2000
[ 147.626834][ T241] rbtree testing
[ 148.032627][ T241] -> test 1 (latency of nnodes insert+delete):
1051510 cycles
[ 148.439514][ T241] -> test 2 (latency of nnodes cached
insert+delete): 1049853 cycles
[ 148.465867][ T241] -> test 3 (latency of inorder traversal): 63728 cycles
[ 148.466980][ T241] -> test 4 (latency to fetch first node)
[ 148.468084][ T241] non-cached: 24 cycles
[ 148.468941][ T241] cached: 13 cycles
[ 172.494679][ C0] watchdog: BUG: soft lockup - CPU#0 stuck for
22s! [modprobe:241]
[ 172.495922][ C0] Modules linked in: rbtree_test(E+)
crc32_pclmul(E) ghash_clmulni_intel(E) crct10dif_pclmul(E)
crc32c_intel(E) serio_raw(E)
[ 172.497859][ C0] CPU: 0 PID: 241 Comm: modprobe Tainted: G
E 5.8.0-rc3-00017-gcd430eec8fdf #190
[ 172.499592][ C0] Hardware name: QEMU Standard PC (i440FX + PIIX,
1996), BIOS 1.13.0-2.fc32 04/01/2014
[ 172.501049][ C0] RIP: 0010:__sanitizer_cov_trace_pc+0x30/0x60
[ 172.501937][ C0] Code: 8b 14 25 40 7c 01 00 65 8b 05 7c ca d6 7e
a9 00 01 ff 00 74 0f f6 c4 01 74 3c 8b 82 cc 19 00 00 85 c0 74 32 8b
82 a8 19 00 00 <83> f8 02 75 27 48 8b b2 b0 19 00 00 8b 92 ac 19 00 00
48 8b 06 48
[ 172.505047][ C0] RSP: 0018:ffffc900000ebd38 EFLAGS: 00000246
[ 172.506028][ C0] RAX: 0000000000000000 RBX: 0000000000000007
RCX: ffffffffc002619e
[ 172.507369][ C0] RDX: ffff88800776ddc0 RSI: ffffffffc0028460
RDI: ffff888004c0b480
[ 172.508651][ C0] RBP: 0000000000000537 R08: ffff888004c03190
R09: 0000000000000000
[ 172.509815][ C0] R10: ffff888004c13798 R11: 0000000031343254
R12: ffff888004c03190
[ 172.511013][ C0] R13: 000000000000005d R14: 0000000000000001
R15: 0000000011e954f4
[ 172.512316][ C0] FS: 00007f4173fcd740(0000)
GS:ffff888007a00000(0000) knlGS:0000000000000000
[ 172.513627][ C0] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 172.514646][ C0] CR2: 000055ae6dee3660 CR3: 0000000005c3a005
CR4: 0000000000360ef0
[ 172.516089][ C0] DR0: 0000000000000000 DR1: 0000000000000000
DR2: 0000000000000000
[ 172.517247][ C0] DR3: 0000000000000000 DR6: 00000000fffe0ff0
DR7: 0000000000000400
[ 172.518529][ C0] Call Trace:
[ 172.519032][ C0] check+0xcd/0x230 [rbtree_test]
[ 172.519801][ C0] rbtree_test_init+0x4a2/0x1000 [rbtree_test]
[ 172.520827][ C0] ? 0xffffffffc0016000
[ 172.521582][ C0] do_one_initcall+0x5f/0x270
[ 172.522263][ C0] ? _cond_resched+0x16/0x40
[ 172.522913][ C0] ? kmem_cache_alloc_trace+0x1eb/0x220
[ 172.523741][ C0] ? do_init_module+0x23/0x250
[ 172.524539][ C0] do_init_module+0x5c/0x250
[ 172.525239][ C0] __do_sys_finit_module+0xac/0x110
[ 172.526245][ C0] do_syscall_64+0x4d/0x90
[ 172.527034][ C0] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 172.528178][ C0] RIP: 0033:0x7f41740f743d
[ 172.529006][ C0] Code: Bad RIP value.
[ 172.529693][ C0] RSP: 002b:00007ffc31454ea8 EFLAGS: 00000246
ORIG_RAX: 0000000000000139
[ 172.531206][ C0] RAX: ffffffffffffffda RBX: 000055ac3eac3b40
RCX: 00007f41740f743d
[ 172.532539][ C0] RDX: 0000000000000000 RSI: 000055ac3eac3e10
RDI: 0000000000000003
[ 172.533709][ C0] RBP: 0000000000040000 R08: 0000000000000000
R09: 000000000000000b
[ 172.534860][ C0] R10: 0000000000000003 R11: 0000000000000246
R12: 0000000000000000
[ 172.535983][ C0] R13: 000055ac3eac3e10 R14: 000055ac3eac3be0
R15: 000000000000000b
[ 183.785924][ T241] augmented rbtree testing
[ 184.431255][ T241] -> test 1 (latency of nnodes insert+delete):
1672622 cycles
[ 185.082000][ T241] -> test 2 (latency of nnodes cached
insert+delete): 1681097 cycles
[ 207.628654][ C0] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 207.629842][ C0] (detected by 0, t=60002 jiffies, g=24045, q=4)
[ 207.631329][ C0] rcu: All QSes seen, last rcu_sched kthread
activity 60002 (4294874745-4294814743), jiffies_till_next_fqs=3, root
->qsmask 0x0
[ 207.633795][ C0] rcu: rcu_sched kthread starved for 60002
jiffies! g24045 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[ 207.635773][ C0] rcu: Unless rcu_sched kthread gets sufficient
CPU time, OOM is now expected behavior.
[ 207.637720][ C0] rcu: RCU grace-period kthread stack dump:
[ 207.638771][ C0] rcu_sched R running task 0 11
2 0x00004000
[ 207.640034][ C0] Call Trace:
[ 207.640791][ C0] __schedule+0x27d/0x780
[ 207.641831][ C0] ? __mod_timer+0x27f/0x540
[ 207.642706][ C0] schedule+0x4a/0xb0
[ 207.643324][ C0] schedule_timeout+0xa9/0x1a0
[ 207.644207][ C0] ? __next_timer_interrupt+0x110/0x110
[ 207.645320][ C0] rcu_gp_kthread+0x4a2/0xa70
[ 207.646391][ C0] ? rcu_barrier+0x200/0x200
[ 207.647267][ C0] kthread+0x13c/0x160
[ 207.648177][ C0] ? __kthread_bind_mask+0x80/0x80
[ 207.649102][ C0] ret_from_fork+0x22/0x30
[ 230.366727][ T241] dynamic_debug:ddebug_remove_module: removing
module "rbtree_test"
modprobe: ERROR: could not insert 'rbtree_test': Resource temporarily
unavailable
bash-5.0#
_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
^ permalink raw reply [flat|nested] only message in thread
only message in thread, other threads:[~2020-07-03 21:16 UTC | newest]
Thread overview: (only message) (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-07-03 21:15 modprobe rbtree-test nnodes=1000 gets soft lockup jim.cromie
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.