Subject: Re: [linux-next][s390] Boot hang after merge c50f05bd3c4e (sched/hrtick)

From: Mikhail Zaslonko <[email-masked]>
Date: Wed, 4 Mar 2026 17:13:56 +0100

Sorry, forgot to Cc a few people.
Adding scheduler maintainers.

Thanks,
Mikhail Zaslonko

On 03-Mar-26 19:31, Mikhail Zaslonko wrote:
> Hello,
> 
> we have kernel-next boot hang on s390 starting next-20260302.
> 
> I bisected it in linux-next to:
> 
> c50f05bd3c4e ("Merge branch into tip/master: 'sched/hrtick'")
> 
> Good:
>   72a2ab46f045  
>   d50da4b5915f  (2nd parent: sched/hrtick branch)
> 
> Bad:
>   c50f05bd3c4e  (merge commit)
> 
> Environment:
>  - s390 under z/VM
>  - many CPUs defined (32+)
>  - boot hangs early with RCU stall (see boot log excerpt below)
> 
> 
> 
> [    0.953192] Freeing unused kernel image (initmem) memory: 2520K                                                     
> [    0.962509] Write protected read-only-after-init data: 188k                                                         
> [    0.962884] Checked W+X mappings: passed, no W+X pages found                                                        
> [    0.962888] Run /init as init process                                                                               
>  P+q6E616D65 \[   29.503589] systemd[1]: Inserted module 'autofs4'                                                     
>                                                                                                                        
> hangs here, no logs ...                                                                                                                       
>                                                                                                                        
> [   98.619693] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:                                                     
> [   98.619708] rcu:     4-...!: (1 GPs behind) idle=04a8/0/0x0 softirq=25/26 fqs=0 (false positive?)                   
> [   98.619715] rcu:     5-...!: (1 GPs behind) idle=04b8/0/0x0 softirq=25/26 fqs=0 (false positive?)                   
> [   98.619720] rcu:     6-...!: (1 GPs behind) idle=04a8/0/0x0 softirq=23/24 fqs=0 (false positive?)                   
> [   98.619724] rcu:     7-...!: (1 GPs behind) idle=04e8/0/0x0 softirq=28/29 fqs=0 (false positive?)                   
> [   98.619729] rcu:     8-...!: (1 GPs behind) idle=0568/0/0x0 softirq=27/28 fqs=0 (false positive?)                   
> [   98.619733] rcu:     9-...!: (1 GPs behind) idle=04e8/0/0x0 softirq=35/36 fqs=0 (false positive?)                   
> [   98.619737] rcu:     10-...!: (1 GPs behind) idle=0518/0/0x0 softirq=33/34 fqs=0 (false positive?)                  
> [   98.619742] rcu:     11-...!: (1 GPs behind) idle=0448/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619745] rcu:     12-...!: (1 GPs behind) idle=0488/0/0x0 softirq=23/24 fqs=0 (false positive?)                  
> [   98.619749] rcu:     13-...!: (1 GPs behind) idle=04a8/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619753] rcu:     14-...!: (0 ticks this GP) idle=0498/0/0x0 softirq=26/26 fqs=0 (false positive?)               
> [   98.619758] rcu:     15-...!: (1 GPs behind) idle=0448/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619762] rcu:     16-...!: (1 GPs behind) idle=0458/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619766] rcu:     17-...!: (1 GPs behind) idle=0438/0/0x0 softirq=21/22 fqs=0 (false positive?)                  
> [   98.619770] rcu:     18-...!: (1 GPs behind) idle=03e8/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619774] rcu:     19-...!: (1 GPs behind) idle=0458/0/0x0 softirq=22/23 fqs=0 (false positive?)                  
> [   98.619778] rcu:     20-...!: (1 GPs behind) idle=04b8/0/0x0 softirq=24/25 fqs=0 (false positive?)                  
> [   98.619782] rcu:     21-...!: (1 GPs behind) idle=04b8/0/0x0 softirq=23/24 fqs=0 (false positive?)                  
> [   98.619786] rcu:     22-...!: (1 GPs behind) idle=04d8/0/0x0 softirq=23/24 fqs=0 (false positive?)                  
> [   98.619790] rcu:     23-...!: (1 GPs behind) idle=0b68/0/0x0 softirq=29/30 fqs=0 (false positive?)                  
> [   98.619794] rcu:     24-...!: (1 GPs behind) idle=0508/0/0x0 softirq=25/26 fqs=0 (false positive?)                  
> [   98.619798] rcu:     25-...!: (1 GPs behind) idle=10c8/0/0x0 softirq=38/39 fqs=0 (false positive?)                  
> [   98.619802] rcu:     28-...!: (1 GPs behind) idle=0518/0/0x0 softirq=25/26 fqs=0 (false positive?)                  
> [   98.619806] rcu:     30-...!: (1 GPs behind) idle=0518/0/0x0 softirq=20/21 fqs=0 (false positive?)                  
> [   98.619810] rcu:     31-...!: (1 GPs behind) idle=0528/0/0x0 softirq=23/24 fqs=0 (false positive?)                  
> [   98.619815] rcu:     (detected by 0, t=69116 jiffies, g=-1019, q=494 ncpus=32)                                      
> [   98.619818] Task dump for CPU 4:       
> [   98.619820] task:swapper/4       state:R  running task     stack:0     pid:0     tgid:0     ppid:1      task_flags:0x4200042 flags:0x0
> [   98.619825] Call Trace:                                                                                                               
> [   98.619828]  [<000001b02c9afd98>] 0x1b02c9afd98                                                                                       
> [   98.619834] Task dump for CPU 5:                                                                                                      
> [   98.619835] task:swapper/5       state:R  running task     stack:0     pid:0     tgid:0     ppid:1      task_flags:0x4200042 flags:0x0
> [   98.619838] Call Trace:                                                                                                               
> [   98.619839]  [<000001b02c9b7d98>] 0x1b02c9b7d98                                                                                       
> [   98.619841] Task dump for CPU 6:                                                                                                      
> 
> ...
>                                                                                                  
> [   98.619963] Task dump for CPU 31:                                                                                                                     
> [   98.619964] task:swapper/31      state:R  running task     stack:0     pid:0     tgid:0     ppid:1      task_flags:0x4200042 flags:0x00001000         
> [   98.619967] Call Trace:                                                                                                                               
> [   98.619967]  [<000001b02ca87d98>] 0x1b02ca87d98                                                                                                       
> [   98.619969] rcu: rcu_sched kthread timer wakeup didn't happen for 69113 jiffies! g-1019 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402                         
> [   98.620052] rcu:     Possible timer handling issue on cpu=3 timer-softirq=12                                                                          
> [   98.620055] rcu: rcu_sched kthread starved for 69116 jiffies! g-1019 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=3                                    
> [   98.620058] rcu:     Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.                                                 
> [   98.620060] rcu: RCU grace-period kthread stack dump:                                                                                                 
> [   98.620062] task:rcu_sched       state:I stack:0     pid:15    tgid:15    ppid:2      task_flags:0x208040 flags:0x00000000                            
> [   98.620067] Call Trace:                                                                                                                               
> [   98.620068]  [<000002302d9d58ac>] __schedule+0x35c/0x850                                                                                              
> [   98.620077]  [<000002302d9d5ddc>] schedule+0x3c/0xc0                                                                                                  
> [   98.620080]  [<000002302d9de418>] schedule_timeout+0x88/0x120                                                                                         
> [   98.620084]  [<000002302cbfd29a>] rcu_gp_fqs_loop+0x69a/0x8a0                                                                                         
> [   98.620090]  [<000002302cc03426>] rcu_gp_kthread+0x2d6/0x340                                                                                          
> [   98.620093]  [<000002302cb82d18>] kthread+0x148/0x170                                                                                                 
> [   98.620098]  [<000002302cb01ffc>] __ret_from_fork+0x3c/0x240                                                                                          
> [   98.620103]  [<000002302d9dfb82>] ret_from_fork+0xa/0x30                                                                                              
> [   98.620106] rcu: Stack dump where RCU GP kthread last ran:                                                                                            
> [   98.620108] Task dump for CPU 3:                                                                                                                      
> [   98.620110] task:swapper/3       state:R  running task     stack:0     pid:0     tgid:0     ppid:1      task_flags:0x4200042 flags:0x00001000         
> [   98.620114] Call Trace:                                                                                                                                                 
> 
> 
> 
>