modprobe rbtree-test nnodes=1000 gets soft lockup
jim.cromie at gmail.com
jim.cromie at gmail.com
Fri Jul 3 17:15:29 EDT 2020
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#
More information about the Kernelnewbies
mailing list