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>] [day] [month] [year] [list]
Message-ID: <202209131658.a3549a75-yujie.liu@intel.com>
Date:   Tue, 13 Sep 2022 17:13:01 +0800
From:   kernel test robot <yujie.liu@...el.com>
To:     Peter Zijlstra <peterz@...radead.org>
CC:     <lkp@...ts.01.org>, <lkp@...el.com>,
        Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
        Tim Chen <tim.c.chen@...ux.intel.com>,
        Borislav Petkov <bp@...e.de>,
        Josh Poimboeuf <jpoimboe@...nel.org>,
        "Thadeu Lima de Souza Cascardo" <cascardo@...onical.com>,
        Ben Hutchings <ben@...adent.org.uk>,
        <linux-kernel@...r.kernel.org>, <linux-pm@...r.kernel.org>
Subject: [intel_idle] 55bba093fd: WARNING:suspicious_RCU_usage

Greeting,

FYI, we noticed the following commit (built with gcc-11):

commit: 55bba093fd91a76971134e3a4e3576e536c08f5c ("intel_idle: Disable IBRS during long idle")
https://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable-rc.git linux-5.10.y

in testcase: kernel-selftests
version: kernel-selftests-x86_64-700a8991-1_20220823
with following parameters:

	group: ftrace

test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt


on test machine: 8 threads Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz (Skylake) with 16G memory

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


[  247.216403][    T0] =============================                                                 
[  247.221176][    T0] WARNING: suspicious RCU usage                                                 
[  247.225953][    T0] 5.10.132-00105-g55bba093fd91 #1 Tainted: G        W                           
[  247.233367][    T0] -----------------------------                                                 
[  247.238143][    T0] arch/x86/include/asm/msr-trace.h:45 suspicious rcu_dereference_check() usage! 
[  247.247136][    T0]                                                                               
[  247.247136][    T0] other info that might help us debug this:                                     
[  247.247136][    T0]                                                                               
[  247.257350][    T0]                                                                               
[  247.257350][    T0] rcu_scheduler_active = 2, debug_locks = 1                                     
[  247.265377][    T0] RCU used illegally from extended quiescent state!                             
[  247.271911][    T0] no locks held by swapper/6/0.                                                 
[  247.276687][    T0]                                                                               
[  247.276687][    T0] stack backtrace:                                                              
[  247.282521][    T0] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G        W         5.10.132-00105-g55b\
ba093fd91 #1                                                                                         
[  247.292587][    T0] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7                                                                                                    
[  247.301668][    T0] Call Trace:                                                                   
[  247.304880][    T0]  dump_stack+0x9a/0xd0                                                         
[  247.308968][    T0]  trace_write_msr+0x12f/0x140                                                  
[  247.313679][    T0]  intel_idle_ibrs+0x11e/0x180                                                  
[  247.318384][    T0]  cpuidle_enter_state+0x174/0xbc0                                              
[  247.323465][    T0]  cpuidle_enter+0x4a/0xc0                                                      
[  247.327826][    T0]  cpuidle_idle_call+0x280/0x400                                                
[  247.332703][    T0]  ? arch_cpu_idle_exit+0xc0/0xc0                                               
[  247.337653][    T0]  ? trace_hardirqs_off+0x53/0x140                                              
[  247.342709][    T0]  ? do_idle+0xd0/0x1c0
[  247.346785][    T0]  ? rcu_nmi_exit+0x4c/0xc0                                                     
[  247.351210][    T0]  ? tsc_verify_tsc_adjust+0x61/0x240                                           
[  247.356563][    T0]  do_idle+0xd7/0x1c0                                                           
[  247.360478][    T0]  cpu_startup_entry+0x19/0x40                                                  
[  247.365180][    T0]  start_secondary+0x247/0x340                                                  
[  247.369878][    T0]  ? set_cpu_sibling_map+0x24c0/0x24c0                                          
[  247.375319][    T0]  secondary_startup_64_no_verify+0xc2/0xcb                                     
[  247.381266][    C6]                                                                               
[  247.381270][    C6] =============================                                                 
[  247.381273][    C6] WARNING: suspicious RCU usage                                                 
[  247.381277][    C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G        W                           
[  247.381280][    C6] -----------------------------                                                 
[  247.381284][    C6] include/trace/events/lock.h:13 suspicious rcu_dereference_check() usage!      
[  247.381287][    C6]                                                                               
[  247.381290][    C6] other info that might help us debug this:                                     
[  247.381293][    C6]                                                                               
[  247.381296][    C6]                                                                               
[  247.381299][    C6] rcu_scheduler_active = 2, debug_locks = 1                                     
[  247.381303][    C6] RCU used illegally from extended quiescent state!                             
[  247.381306][    C6] no locks held by swapper/6/0.                                                 
[  247.381309][    C6]                                                                               
[  247.381312][    C6] stack backtrace:                                                              
[  247.381316][    C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G        W         5.10.132-00105-g55b\
ba093fd91 #1                                                                                         
[  247.381320][    C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7                                                                                                    
[  247.381323][    C6] Call Trace:                                                                   
[  247.381326][    C6]  dump_stack+0x9a/0xd0                                                         
[  247.381329][    C6]  lock_acquire.cold+0x3b/0x5d                                                  
[  247.381333][    C6]  ? rcu_read_unlock+0x80/0x80                                                  
[  247.381337][    C6]  ? ring_buffer_unlock_commit+0x13f/0x580                                      
[  247.381340][    C6]  ? tracing_generic_entry_update+0x131/0x240                                   
[  247.381343][    C6]  _raw_spin_lock+0x2c/0x40                                                     
[  247.381346][    C6]  ? vprintk_emit+0xba/0x2c0                                                    
[  247.381350][    C6]  vprintk_emit+0xba/0x2c0                                                      
[  247.381353][    C6]  ? trace_event_buffer_commit+0x17c/0xa40                                      
[  247.381356][    C6]  printk+0xb2/0xe7                                                             
[  247.381359][    C6]  ? record_print_text.cold+0x11/0x11                                           
[  247.381363][    C6]  ? trace_write_msr+0x2d/0x140                                                 
[  247.381366][    C6]  lockdep_rcu_suspicious+0x25/0x145                                            
[  247.381369][    C6]  trace_write_msr+0x12f/0x140                                                  
[  247.381372][    C6]  intel_idle_ibrs+0x11e/0x180                                                  
[  247.381376][    C6]  cpuidle_enter_state+0x174/0xbc0                                              
[  247.381379][    C6]  cpuidle_enter+0x4a/0xc0                                                      
[  247.381381][    C6]  cpuidle_idle_call+0x280/0x400                                                
[  247.381383][    C6]  ? arch_cpu_idle_exit+0xc0/0xc0                                               
[  247.381385][    C6]  ? trace_hardirqs_off+0x53/0x140                                              
[  247.381387][    C6]  ? do_idle+0xd0/0x1c0                                                         
[  247.381389][    C6]  ? rcu_nmi_exit+0x4c/0xc0                                                     
[  247.381391][    C6]  ? tsc_verify_tsc_adjust+0x61/0x240                                           
[  247.381394][    C6]  do_idle+0xd7/0x1c0
[  247.381396][    C6]  cpu_startup_entry+0x19/0x40
[  247.381398][    C6]  start_secondary+0x247/0x340
[  247.381400][    C6]  ? set_cpu_sibling_map+0x24c0/0x24c0
[  247.381402][    C6]  secondary_startup_64_no_verify+0xc2/0xcb
[  247.381404][    C6]
[  247.381406][    C6] =============================
[  247.381408][    C6] WARNING: suspicious RCU usage
[  247.381410][    C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G        W
[  247.381412][    C6] -----------------------------
[  247.381414][    C6] include/trace/events/lock.h:58 suspicious rcu_dereference_check() usage!
[  247.381416][    C6]
[  247.381419][    C6] other info that might help us debug this:
[  247.381420][    C6]
[  247.381422][    C6]
[  247.381425][    C6] rcu_scheduler_active = 2, debug_locks = 1
[  247.381427][    C6] RCU used illegally from extended quiescent state!
[  247.381429][    C6] 1 lock held by swapper/6/0:
[  247.381431][    C6]  #0: ffffffff8513b0d8 (logbuf_lock){-.-.}-{2:2}, at: vprintk_emit+0xba/0x2c0
[  247.381444][    C6]
[  247.381446][    C6] stack backtrace:
[  247.381448][    C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G        W         5.10.132-00105-g55b\
ba093fd91 #1
[  247.381450][    C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[  247.381452][    C6] Call Trace:
[  247.381454][    C6]  dump_stack+0x9a/0xd0
[  247.381457][    C6]  ? vprintk_emit+0xdc/0x2c0
[  247.381459][    C6]  lock_release.cold+0x1f/0x38
[  247.381461][    C6]  _raw_spin_unlock+0x17/0x40
[  247.381463][    C6]  vprintk_emit+0xdc/0x2c0
[  247.381465][    C6]  ? trace_event_buffer_commit+0x17c/0xa40
[  247.381467][    C6]  printk+0xb2/0xe7
[  247.381470][    C6]  ? record_print_text.cold+0x11/0x11
[  247.381472][    C6]  ? trace_write_msr+0x2d/0x140
[  247.381474][    C6]  lockdep_rcu_suspicious+0x25/0x145
[  247.381476][    C6]  trace_write_msr+0x12f/0x140
[  247.381478][    C6]  intel_idle_ibrs+0x11e/0x180
[  247.381480][    C6]  cpuidle_enter_state+0x174/0xbc0
[  247.381482][    C6]  cpuidle_enter+0x4a/0xc0
[  247.381484][    C6]  cpuidle_idle_call+0x280/0x400
[  247.381486][    C6]  ? arch_cpu_idle_exit+0xc0/0xc0
[  247.381488][    C6]  ? trace_hardirqs_off+0x53/0x140
[  247.381490][    C6]  ? do_idle+0xd0/0x1c0
[  247.381492][    C6]  ? rcu_nmi_exit+0x4c/0xc0
[  247.381494][    C6]  ? tsc_verify_tsc_adjust+0x61/0x240
[  247.381496][    C6]  do_idle+0xd7/0x1c0
[  247.381499][    C6]  cpu_startup_entry+0x19/0x40
[  247.381502][    C6]  start_secondary+0x247/0x340
[  247.381505][    C6]  ? set_cpu_sibling_map+0x24c0/0x24c0
[  247.381508][    C6]  secondary_startup_64_no_verify+0xc2/0xcb
[  247.381511][    C6]
[  247.381515][    C6] =============================
[  247.381518][    C6] WARNING: suspicious RCU usage
[  247.381521][    C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G        W
[  247.381525][    C6] -----------------------------
[  247.381529][    C6] include/linux/rcupdate.h:652 rcu_read_lock() used illegally while idle!
[  247.381532][    C6]
[  247.381535][    C6] other info that might help us debug this:
[  247.381538][    C6]
[  247.381541][    C6]
[  247.381544][    C6] rcu_scheduler_active = 2, debug_locks = 1
[  247.381548][    C6] RCU used illegally from extended quiescent state!
[  247.381551][    C6] 4 locks held by swapper/6/0:
[  247.381554][    C6]  #0: ffffffff8513b1a0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x1c3/0x2c\
0
[  247.381566][    C6]  #1: ffffffff84dbabc0 (console_owner){-.-.}-{0:0}, at: console_unlock+0x255/0\
x5c0
[  247.381578][    C6]  #2: ffffffff8572eaf8 (printing_lock){....}-{2:2}, at: vt_console_print+0x10d\
/0xcc0
[  247.381590][    C6]  #3: ffffffff85162000 (rcu_read_lock){....}-{1:2}, at: atomic_notifier_call_c\
hain+0x5/0x200
[  247.381603][    C6]
[  247.381605][    C6] stack backtrace:
[  247.381607][    C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G        W         5.10.132-00105-g55b\
ba093fd91 #1
[  247.381609][    C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[  247.381611][    C6] Call Trace:
[  247.381613][    C6]  dump_stack+0x9a/0xd0
[  247.381615][    C6]  atomic_notifier_call_chain+0x16d/0x200
[  247.381618][    C6]  vt_console_print+0x4d3/0xcc0
[  247.381620][    C6]  ? lf+0x2c0/0x2c0
[  247.381622][    C6]  call_console_drivers+0x1dd/0x340
[  247.381624][    C6]  console_unlock+0x2d3/0x5c0
[  247.381626][    C6]  ? console_unlock+0x255/0x5c0
[  247.381628][    C6]  ? devkmsg_read+0x680/0x680
[  247.381630][    C6]  ? __lock_release+0x102/0x540
[  247.381632][    C6]  ? __down_trylock_console_sem+0x68/0xc0
[  247.381634][    C6]  ? vprintk_emit+0x1c3/0x2c0
[  247.381636][    C6]  vprintk_emit+0x247/0x2c0
[  247.381639][    C6]  ? trace_event_buffer_commit+0x17c/0xa40
[  247.381641][    C6]  printk+0xb2/0xe7
[  247.381643][    C6]  ? record_print_text.cold+0x11/0x11
[  247.381645][    C6]  ? trace_write_msr+0x2d/0x140
[  247.381647][    C6]  lockdep_rcu_suspicious+0x25/0x145
[  247.381649][    C6]  trace_write_msr+0x12f/0x140
[  247.381651][    C6]  intel_idle_ibrs+0x11e/0x180
[  247.381653][    C6]  cpuidle_enter_state+0x174/0xbc0
[  247.381655][    C6]  cpuidle_enter+0x4a/0xc0
[  247.381657][    C6]  cpuidle_idle_call+0x280/0x400
[  247.381659][    C6]  ? arch_cpu_idle_exit+0xc0/0xc0
[  247.381661][    C6]  ? trace_hardirqs_off+0x53/0x140
[  247.381663][    C6]  ? do_idle+0xd0/0x1c0
[  247.381665][    C6]  ? rcu_nmi_exit+0x4c/0xc0
[  247.381667][    C6]  ? tsc_verify_tsc_adjust+0x61/0x240
[  247.381669][    C6]  do_idle+0xd7/0x1c0
[  247.381671][    C6]  cpu_startup_entry+0x19/0x40
[  247.381673][    C6]  start_secondary+0x247/0x340
[  247.381676][    C6]  ? set_cpu_sibling_map+0x24c0/0x24c0
[  247.381678][    C6]  secondary_startup_64_no_verify+0xc2/0xcb
[  247.381680][    C6]
[  247.381682][    C6] =============================
[  247.381684][    C6] WARNING: suspicious RCU usage
[  247.381686][    C6] 5.10.132-00105-g55bba093fd91 #1 Tainted: G        W
[  247.381688][    C6] -----------------------------
[  247.381691][    C6] include/linux/rcupdate.h:701 rcu_read_unlock() used illegally while idle!
[  247.381692][    C6]
[  247.381695][    C6] other info that might help us debug this:
[  247.381697][    C6]
[  247.381698][    C6]
[  247.381701][    C6] rcu_scheduler_active = 2, debug_locks = 1
[  247.381703][    C6] RCU used illegally from extended quiescent state!
[  247.381705][    C6] 4 locks held by swapper/6/0:
[  247.381707][    C6]  #0: ffffffff8513b1a0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x1c3/0x2c\
0
[  247.381719][    C6]  #1: ffffffff84dbabc0 (console_owner){-.-.}-{0:0}, at: console_unlock+0x255/0\
x5c0
[  247.381731][    C6]  #2: ffffffff8572eaf8 (printing_lock){....}-{2:2}, at: vt_console_print+0x10d\
/0xcc0
[  247.381743][    C6]  #3: ffffffff85162000 (rcu_read_lock){....}-{1:2}, at: atomic_notifier_call_c\
hain+0x5/0x200
[  247.381755][    C6]
[  247.381757][    C6] stack backtrace:
[  247.381759][    C6] CPU: 6 PID: 0 Comm: swapper/6 Tainted: G        W         5.10.132-00105-g55b\
ba093fd91 #1
[  247.381761][    C6] Hardware name: HP HP Z240 SFF Workstation/802E, BIOS N51 Ver. 01.63 10/05/201\
7
[  247.381763][    C6] Call Trace:
[  247.381765][    C6]  dump_stack+0x9a/0xd0
[  247.381767][    C6]  atomic_notifier_call_chain+0x1b7/0x200
[  247.381769][    C6]  vt_console_print+0x4d3/0xcc0
[  247.381771][    C6]  ? lf+0x2c0/0x2c0
[  247.381774][    C6]  call_console_drivers+0x1dd/0x340
[  247.381776][    C6]  console_unlock+0x2d3/0x5c0
[  247.381778][    C6]  ? console_unlock+0x255/0x5c0
[  247.381780][    C6]  ? devkmsg_read+0x680/0x680
[  247.381782][    C6]  ? __lock_release+0x102/0x540
[  247.381784][    C6]  ? __down_trylock_console_sem+0x68/0xc0
[  247.381786][    C6]  ? vprintk_emit+0x1c3/0x2c0
[  247.381788][    C6]  vprintk_emit+0x247/0x2c0
[  247.381790][    C6]  ? trace_event_buffer_commit+0x17c/0xa40
[  247.381792][    C6]  printk+0xb2/0xe7
[  247.381794][    C6]  ? record_print_text.cold+0x11/0x11
[  247.381797][    C6]  ? trace_write_msr+0x2d/0x140
[  247.381799][    C6]  lockdep_rcu_suspicious+0x25/0x145
[  247.381801][    C6]  trace_write_msr+0x12f/0x140
[  247.381803][    C6]  intel_idle_ibrs+0x11e/0x180
[  247.381805][    C6]  cpuidle_enter_state+0x174/0xbc0
[  247.381807][    C6]  cpuidle_enter+0x4a/0xc0
[  247.381809][    C6]  cpuidle_idle_call+0x280/0x400
[  247.381811][    C6]  ? arch_cpu_idle_exit+0xc0/0xc0
[  247.381813][    C6]  ? trace_hardirqs_off+0x53/0x140
[  247.381815][    C6]  ? do_idle+0xd0/0x1c0
[  247.381817][    C6]  ? rcu_nmi_exit+0x4c/0xc0
[  247.381819][    C6]  ? tsc_verify_tsc_adjust+0x61/0x240
[  247.381821][    C6]  do_idle+0xd7/0x1c0
[  247.381824][    C6]  cpu_startup_entry+0x19/0x40
[  247.381826][    C6]  start_secondary+0x247/0x340
[  247.381828][    C6]  ? set_cpu_sibling_map+0x24c0/0x24c0
[  247.381830][    C6]  secondary_startup_64_no_verify+0xc2/0xcb


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <yujie.liu@...el.com>
Link: https://lore.kernel.org/r/202209131658.a3549a75-yujie.liu@intel.com


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        sudo bin/lkp install job.yaml           # job file is attached in this email
        bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
        sudo bin/lkp run generated-yaml-file

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.


-- 
0-DAY CI Kernel Test Service
https://01.org/lkp

View attachment "config-5.10.132-00105-g55bba093fd91" of type "text/plain" (157861 bytes)

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

Download attachment "dmesg.xz" of type "application/x-xz" (33104 bytes)

View attachment "kernel-selftests" of type "text/plain" (7921 bytes)

View attachment "job.yaml" of type "text/plain" (5096 bytes)

View attachment "reproduce" of type "text/plain" (250 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ