netdev - [lkp-robot] [rhashtable] 60be2ebf32: INFO:suspicious_RCU

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Thu, 9 Feb 2017 10:12:48 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     Herbert Xu <herbert@...dor.apana.org.au>
Cc:     "David S. Miller" <davem@...emloft.net>,
        Thomas Graf <tgraf@...g.ch>, netdev@...r.kernel.org, lkp@...org
Subject: [lkp-robot] [rhashtable]  60be2ebf32: INFO:suspicious_RCU_usage


FYI, we noticed the following commit:

commit: 60be2ebf326aa90c88e9a967412557d832a1612e ("rhashtable: Add nested tables")
url: https://github.com/0day-ci/linux/commits/Herbert-Xu/rhashtable-Handle-table-allocation-failure-during-insertion/20170207-204835


in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 2G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-------------------------------------------------+------------+------------+
|                                                 | 12f609851b | 60be2ebf32 |
+-------------------------------------------------+------------+------------+
| boot_successes                                  | 123        | 5          |
| boot_failures                                   | 9          | 8          |
| BUG:kernel_reboot-without-warning_in_test_stage | 9          |            |
| INFO:suspicious_RCU_usage                       | 0          | 8          |
+-------------------------------------------------+------------+------------+



[  222.678280] [ INFO: suspicious RCU usage. ]
[  222.678280] [ INFO: suspicious RCU usage. ]
[  222.699410] 4.10.0-rc6-00112-g60be2eb #534 Not tainted
[  222.699410] 4.10.0-rc6-00112-g60be2eb #534 Not tainted
[  222.725264] -------------------------------
[  222.725264] -------------------------------
[  222.741887] lib/rhashtable.c:1125 suspicious rcu_dereference_check() usage!
[  222.741887] lib/rhashtable.c:1125 suspicious rcu_dereference_check() usage!
[  222.783537] 
[  222.783537] other info that might help us debug this:
[  222.783537] 
[  222.783537] 
[  222.783537] other info that might help us debug this:
[  222.783537] 
[  222.823615] 
[  222.823615] rcu_scheduler_active = 2, debug_locks = 1
[  222.823615] 
[  222.823615] rcu_scheduler_active = 2, debug_locks = 1
[  222.856672] 4 locks held by kworker/0:1/19:
[  222.856672] 4 locks held by kworker/0:1/19:
[  222.877765]  #0:  ("events"){.+.+.+}, at: [<ffffffff810e6bf5>] process_one_work+0x2ac/0x761
[  222.877765]  #0:  ("events"){.+.+.+}, at: [<ffffffff810e6bf5>] process_one_work+0x2ac/0x761
[  222.917921]  #1:  ((&ht->run_work)){+.+.+.}, at: [<ffffffff810e6c1f>] process_one_work+0x2d6/0x761
[  222.917921]  #1:  ((&ht->run_work)){+.+.+.}, at: [<ffffffff810e6c1f>] process_one_work+0x2d6/0x761
[  222.960763]  #2:  (&ht->mutex){+.+.+.}, at: [<ffffffff8145b13a>] rht_deferred_worker+0x22/0x26a
[  222.960763]  #2:  (&ht->mutex){+.+.+.}, at: [<ffffffff8145b13a>] rht_deferred_worker+0x22/0x26a
[  223.004378]  #3:  (&(&tbl->locks[i])->rlock){+.....}, at: [<ffffffff8145abce>] rhashtable_rehash_table+0xf6/0x640
[  223.004378]  #3:  (&(&tbl->locks[i])->rlock){+.....}, at: [<ffffffff8145abce>] rhashtable_rehash_table+0xf6/0x640
[  223.055769] 
[  223.055769] stack backtrace:
[  223.055769] 
[  223.055769] stack backtrace:
[  223.078034] CPU: 0 PID: 19 Comm: kworker/0:1 Not tainted 4.10.0-rc6-00112-g60be2eb #534
[  223.078034] CPU: 0 PID: 19 Comm: kworker/0:1 Not tainted 4.10.0-rc6-00112-g60be2eb #534
[  223.118613] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  223.118613] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  223.169614] Workqueue: events rht_deferred_worker
[  223.169614] Workqueue: events rht_deferred_worker
[  223.193302] Call Trace:
[  223.193302] Call Trace:
[  223.205882]  dump_stack+0x19/0x1b
[  223.205882]  dump_stack+0x19/0x1b
[  223.222639]  lockdep_rcu_suspicious+0xdd/0xf4
[  223.222639]  lockdep_rcu_suspicious+0xdd/0xf4
[  223.244610]  rht_bucket_nested+0x107/0x10c
[  223.244610]  rht_bucket_nested+0x107/0x10c
[  223.265382]  rhashtable_rehash_table+0x373/0x640
[  223.265382]  rhashtable_rehash_table+0x373/0x640
[  223.289295]  rht_deferred_worker+0x112/0x26a
[  223.289295]  rht_deferred_worker+0x112/0x26a
[  223.308573]  process_one_work+0x3b7/0x761
[  223.308573]  process_one_work+0x3b7/0x761
[  223.328696]  ? process_one_work+0x2d6/0x761
[  223.328696]  ? process_one_work+0x2d6/0x761
[  223.349210]  worker_thread+0x2aa/0x6a5
[  223.349210]  worker_thread+0x2aa/0x6a5
[  223.368199]  kthread+0x107/0x13a
[  223.368199]  kthread+0x107/0x13a
[  223.384633]  ? process_one_work+0x761/0x761
[  223.384633]  ? process_one_work+0x761/0x761
[  223.405721]  ? __kthread_create_on_node+0x232/0x232
[  223.405721]  ? __kthread_create_on_node+0x232/0x232
[  223.430350]  ret_from_fork+0x31/0x40
[  223.430350]  ret_from_fork+0x31/0x40
[  223.448309] 
[  223.448309] 
[  223.456052] ===============================
[  223.456052] ===============================
[  223.477118] [ INFO: suspicious RCU usage. ]
[  223.477118] [ INFO: suspicious RCU usage. ]
[  223.498249] 4.10.0-rc6-00112-g60be2eb #534 Not tainted
[  223.498249] 4.10.0-rc6-00112-g60be2eb #534 Not tainted
[  223.524590] -------------------------------
[  223.524590] -------------------------------
[  223.545889] lib/rhashtable.c:1130 suspicious rcu_dereference_check() usage!
[  223.545889] lib/rhashtable.c:1130 suspicious rcu_dereference_check() usage!
[  223.588207] 
[  223.588207] other info that might help us debug this:
[  223.588207] 
[  223.588207] 
[  223.588207] other info that might help us debug this:
[  223.588207] 
[  223.630761] 
[  223.630761] rcu_scheduler_active = 2, debug_locks = 1
[  223.630761] 
[  223.630761] rcu_scheduler_active = 2, debug_locks = 1
[  223.663675] 4 locks held by kworker/0:1/19:
[  223.663675] 4 locks held by kworker/0:1/19:
[  223.684903]  #0:  ("events"){.+.+.+}, at: [<ffffffff810e6bf5>] process_one_work+0x2ac/0x761
[  223.684903]  #0:  ("events"){.+.+.+}, at: [<ffffffff810e6bf5>] process_one_work+0x2ac/0x761
[  223.727266]  #1:  ((&ht->run_work)){+.+.+.}, at: [<ffffffff810e6c1f>] process_one_work+0x2d6/0x761
[  223.727266]  #1:  ((&ht->run_work)){+.+.+.}, at: [<ffffffff810e6c1f>] process_one_work+0x2d6/0x761
[  223.772273]  #2:  (&ht->mutex){+.+.+.}, at: [<ffffffff8145b13a>] rht_deferred_worker+0x22/0x26a
[  223.772273]  #2:  (&ht->mutex){+.+.+.}, at: [<ffffffff8145b13a>] rht_deferred_worker+0x22/0x26a
[  223.815952]  #3:  (&(&tbl->locks[i])->rlock){+.....}, at: [<ffffffff8145abce>] rhashtable_rehash_table+0xf6/0x640
[  223.815952]  #3:  (&(&tbl->locks[i])->rlock){+.....}, at: [<ffffffff8145abce>] rhashtable_rehash_table+0xf6/0x640
[  223.867261] 
[  223.867261] stack backtrace:
[  223.867261] 
[  223.867261] stack backtrace:
[  223.889319] CPU: 0 PID: 19 Comm: kworker/0:1 Not tainted 4.10.0-rc6-00112-g60be2eb #534
[  223.889319] CPU: 0 PID: 19 Comm: kworker/0:1 Not tainted 4.10.0-rc6-00112-g60be2eb #534
[  223.929997] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  223.929997] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  223.981005] Workqueue: events rht_deferred_worker
[  223.981005] Workqueue: events rht_deferred_worker
[  224.004663] Call Trace:
[  224.004663] Call Trace:
[  224.017225]  dump_stack+0x19/0x1b
[  224.017225]  dump_stack+0x19/0x1b
[  224.034147]  lockdep_rcu_suspicious+0xdd/0xf4
[  224.034147]  lockdep_rcu_suspicious+0xdd/0xf4
[  224.056211]  rht_bucket_nested+0xb1/0x10c
[  224.056211]  rht_bucket_nested+0xb1/0x10c
[  224.076497]  rhashtable_rehash_table+0x373/0x640
[  224.076497]  rhashtable_rehash_table+0x373/0x640
[  224.099931]  rht_deferred_worker+0x112/0x26a
[  224.099931]  rht_deferred_worker+0x112/0x26a
[  224.122059]  process_one_work+0x3b7/0x761
[  224.122059]  process_one_work+0x3b7/0x761
[  224.142702]  ? process_one_work+0x2d6/0x761
[  224.142702]  ? process_one_work+0x2d6/0x761
[  224.163871]  worker_thread+0x2aa/0x6a5
[  224.163871]  worker_thread+0x2aa/0x6a5
[  224.182764]  kthread+0x107/0x13a
[  224.182764]  kthread+0x107/0x13a
[  224.199164]  ? process_one_work+0x761/0x761
[  224.199164]  ? process_one_work+0x761/0x761
[  224.220351]  ? __kthread_create_on_node+0x232/0x232
[  224.220351]  ? __kthread_create_on_node+0x232/0x232
[  224.244855]  ret_from_fork+0x31/0x40
[  224.244855]  ret_from_fork+0x31/0x40
[  234.724349] Started 10 threads, 0 failed
[  234.724349] Started 10 threads, 0 failed
[  234.962237] test_printf: all 260 tests passed
[  234.962237] test_printf: all 260 tests passed
[  235.933585] test_bitmap: all 460506 tests passed
[  235.933585] test_bitmap: all 460506 tests passed
[  235.974966] test_uuid: all 18 tests passed
[  235.974966] test_uuid: all 18 tests passed
[  236.023025] glob: 64 self-tests passed, 0 failed
[  236.023025] glob: 64 self-tests passed, 0 failed
[  236.048527] rbtree testing
[  236.048527] rbtree testing
[  243.915063]  -> 177860 cycles
[  243.915063]  -> 177860 cycles
[  245.007005] augmented rbtree testing
[  245.007005] augmented rbtree testing
[  254.991361]  -> 225745 cycles
[  254.991361]  -> 225745 cycles
[  256.827942] gpio_it87: no device
[  256.827942] gpio_it87: no device
[  256.853015] gpio-mockup: probe of gpio-mockup failed with error -22
[  256.853015] gpio-mockup: probe of gpio-mockup failed with error -22
[  256.918377] cr_bllcd: INTEL CARILLO RANCH LPC not found.
[  256.918377] cr_bllcd: INTEL CARILLO RANCH LPC not found.
[  256.946920] cr_bllcd: Carillo Ranch Backlight Driver Initialized.
[  256.946920] cr_bllcd: Carillo Ranch Backlight Driver Initialized.
[  256.997383] vmlfb: initializing
[  256.997383] vmlfb: initializing
[  257.017758] no IO addresses supplied
[  257.017758] no IO addresses supplied
[  257.040767] hgafb: HGA card not detected.
[  257.040767] hgafb: HGA card not detected.
[  257.062684] hgafb: probe of hgafb.0 failed with error -22
[  257.062684] hgafb: probe of hgafb.0 failed with error -22
[  257.102876] uvesafb: failed to execute /sbin/v86d
[  257.102876] uvesafb: failed to execute /sbin/v86d
[  257.126137] uvesafb: make sure that the v86d helper is installed and executable
[  257.126137] uvesafb: make sure that the v86d helper is installed and executable


To reproduce:

        git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.10.0-rc6-00112-g60be2eb" of type "text/plain" (104882 bytes)

View attachment "job-script" of type "text/plain" (4211 bytes)

Download attachment "dmesg.xz" of type "application/octet-stream" (16528 bytes)