modprobe rbtree-test nnodes=1000 gets soft lockup

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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@xxxxxxxxxxxxxxxxx
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies



[Index of Archives]     [Newbies FAQ]     [Linux Kernel Mentors]     [Linux Kernel Development]     [IETF Annouce]     [Git]     [Networking]     [Security]     [Bugtraq]     [Yosemite]     [MIPS Linux]     [ARM Linux]     [Linux RAID]     [Linux SCSI]     [Linux ACPI]

  Powered by Linux