Rock 5C High CPU usage ksoftirqd/0 (kernel 6.1)

avaf · August 24, 2024, 6:37pm

I am trying to find out what is causing 100% CPU usage after a long period of rendering video (from the csi camera and > 24h) on screen on my Rock 5C with kernel 6.1.43.

It’s not always, it happens on some occasions. When it happens, if i stop the process it usually gets to a normal idle state (0% CPU usage).

But this time even after the process is stopped the 100% CPU (cpu0) remained.

Here is the TOP output info in idle mode after the application is stopped:

Tasks: 197 total,   2 running, 195 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  1.1 sy,  0.0 ni, 87.5 id,  0.0 wa,  0.0 hi, 11.4 si,  0.0 st
MiB Mem :   1973.6 total,   1411.3 free,    206.7 used,    355.6 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.   1707.7 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                        
     13 root      20   0       0      0      0 R 100.0   0.0   1051:23 ksoftirqd/0                                                                    
  82624 root      20   0       0      0      0 I   0.3   0.0   0:00.05 kworker/u16:0-devfreq_wq                                                       
      1 root      20   0  165940  10208   7396 S   0.0   0.5   0:03.47 systemd                                                                        
      2 root      20   0       0      0      0 S   0.0   0.0   0:00.24 kthreadd                                                                       
      3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp                                                                         
      4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp                                                                     
      5 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 slub_flushwq                                                                   
      6 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 netns                                                                          
     10 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq                                                                   
     11 root      20   0       0      0      0 I   0.0   0.0   0:00.00 rcu_tasks_rude_kthread                                                         
     12 root      20   0       0      0      0 I   0.0   0.0   0:00.00 rcu_tasks_trace_kthread                                                        
     14 root      20   0       0      0      0 I   0.0   0.0   1:54.21 rcu_sched                                                                      
     15 root      rt   0       0      0      0 S   0.0   0.0   0:01.08 migration/0                                                                    
     16 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/0                                                                        
     17 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/1                                                                        
     18 root      rt   0       0      0      0 S   0.0   0.0   0:00.78 migration/1                                                                    
     19 root      20   0       0      0      0 S   0.0   0.0   0:00.26 ksoftirqd/1                                                                    
     22 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/2                                                                        
     23 root      rt   0       0      0      0 S   0.0   0.0   0:00.00 migration/2                                                                    
     24 root      20   0       0      0      0 S   0.0   0.0   0:00.17 ksoftirqd/2                                                                    
     27 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/3                                                                        
     28 root      rt   0       0      0      0 S   0.0   0.0   0:00.78 migration/3                                                                    
     29 root      20   0       0      0      0 S   0.0   0.0   0:00.16 ksoftirqd/3

And a dump of interrupts after the application is stopped:

   CPU0       CPU1       CPU2       CPU3       CPU4       CPU5       CPU6       CPU7       
  9:          0          0          0          0          0          0          0          0     GICv3  25 Level     vgic
 11:          0          0          0          0          0          0          0          0     GICv3  30 Level     kvm guest ptimer
 12:          0          0          0          0          0          0          0          0     GICv3  27 Level     kvm guest vtimer
 13:   20955352     596501     510036     452669     336967     567668     817131    1472803     GICv3  26 Level     arch_timer
 14:    2575640    1386596    1033443     827104    2215269    1025603    2217351    4503755     GICv3 321 Level     rk_timer
 20:          0          0          0          0          0          0          0          0     GICv3 455 Edge      debug-signal
 21:          0          0          0          0          0          0          0          0     GICv3 365 Level     debug
 22:          0          0          0          0          0          0          0          0     GICv3 429 Level     rockchip_thermal
 23:          0          0          0          0          0          0          0          0     GICv3  23 Level     arm-pmu
 24:          0          0          0          0          0          0          0          0     GICv3 425 Level     rockchip_usb2phy
 25:          1          0          0          0          0          0          0          0     GICv3 423 Level     rockchip_usb2phy
 26:          2          0          0          0          0          0          0          0     GICv3 424 Level     rockchip_usb2phy
 29:         10          0          0          0          0          0          0          0     GICv3 118 Level     fea10000.dma-controller
 30:          0          0          0          0          0          0          0          0     GICv3 119 Level     fea10000.dma-controller
 31:          0          0          0          0          0          0          0          0     GICv3 120 Level     fea30000.dma-controller
 32:          0          0          0          0          0          0          0          0     GICv3 121 Level     fea30000.dma-controller
 33:          5          0          0          0          0          0          0          0     GICv3 122 Level     fed10000.dma-controller
 34:          0          0          0          0          0          0          0          0     GICv3 123 Level     fed10000.dma-controller
 35:          0          0          0          0          0          0          0          0     GICv3 142 Level     fdab9000.iommu, fdab0000.npu
 36:          0          0          0          0          0          0          0          0     GICv3 143 Level     fdab9000.iommu, fdab0000.npu
 37:          0          0          0          0          0          0          0          0     GICv3 144 Level     fdab9000.iommu, fdab0000.npu
 38:          0          0          0          0          0          0          0          0     GICv3 150 Level     fdb50800.iommu
 39:    1342415          0          0          0          0          0          0          0     GICv3 146 Level     fdb60f00.iommu, rga3_core0
 40:          0          0          0          0          0          0          0          0     GICv3 147 Level     fdb70f00.iommu, rga3_core1
 41:          0          0          0          0          0          0          0          0     GICv3 162 Level     fdb90480.iommu
 42:          0          0          0          0          0          0          0          0     GICv3 153 Level     fdba0800.iommu
 43:          0          0          0          0          0          0          0          0     GICv3 155 Level     fdba4800.iommu
 44:          0          0          0          0          0          0          0          0     GICv3 157 Level     fdba8800.iommu
 45:          0          0          0          0          0          0          0          0     GICv3 159 Level     fdbac800.iommu
 46:          0          0          0          0          0          0          0          0     GICv3 149 Level     fdbb0800.iommu, fdbb0000.iep
 47:          0          0          0          0          0          0          0          0     GICv3 131 Level     fdbdf000.iommu
 48:          0          0          0          0          0          0          0          0     GICv3 132 Level     fdbdf000.iommu
 49:          0          0          0          0          0          0          0          0     GICv3 134 Level     fdbef000.iommu
 50:          0          0          0          0          0          0          0          0     GICv3 135 Level     fdbef000.iommu
 51:          0          0          0          0          0          0          0          0     GICv3 128 Level     fdc38700.iommu
 52:          0          0          0          0          0          0          0          0     GICv3 130 Level     fdc48700.iommu
 53:          0          0          0          0          0          0          0          0     GICv3 141 Level     fdca0000.iommu
 54:          0          0          0          0          0          0          0          0     GICv3 164 Level     fdcb7f00.iommu
 55:          0          0          0          0          0          0          0          0     GICv3 145 Level     fdce0800.iommu
 56:    3085358          0          0          0          0          0          0          0     GICv3 188 Level     fdd97e00.iommu, fdd90000.vop
 57:          0          0          0          0          0          0          0          0     GICv3 392 Level     dw-hdmi-qp-hpd
 58:          0          0          0          0          0          0          0          0     GICv3 201 Level     fde80000.hdmi
 59:          0          0          0          0          0          0          0          0     GICv3 202 Level     dw-hdmi-qp-cec
 60:          0          0          0          0          0          0          0          0     GICv3 203 Level     fde80000.hdmi
 61:        323          0          0          0          0          0          0          0     GICv3 204 Level     fde80000.hdmi
 62:     250371          0          0          0          0          0          0          0     GICv3 360 Level     feb20000.spi
 63:          0          0          0          0          0          0          0          0  rockchip_gpio_irq   7 Level     rk806
 64:          0          0          0          0          0          0          0          0     rk806   0 Edge      rk805_pwrkey_fall
 65:          0          0          0          0          0          0          0          0     rk806   1 Edge      rk805_pwrkey_rise
 66:          0          0          0          0          0          0          0          0     rk806   7 Level     rk806_vb_low
 67:     198156          0          0          0          0          0          0          0     GICv3 266 Level     eth0
 68:          0          0          0          0          0          0          0          0     GICv3 265 Level     eth0
 69:          0          0          0          0          0          0          0          0     GICv3 252 Level     xhci-hcd:usb1
 70:          0          0          0          0          0          0          0          0     GICv3 254 Level     xhci-hcd:usb3
 71:      66140          0          0          0          0          0          0          0     GICv3 247 Level     ehci_hcd:usb5
 72:          0          0          0          0          0          0          0          0     GICv3 250 Level     ehci_hcd:usb7
 73:          0          0          0          0          0          0          0          0     GICv3 248 Level     ohci_hcd:usb6
 74:          0          0          0          0          0          0          0          0     GICv3 251 Level     ohci_hcd:usb8
 75:     495490          0          0          0          0          0          0          0     GICv3 349 Level     fd880000.i2c
 76:         58          0          0          0          0          0          0          0     GICv3 351 Level     feaa0000.i2c
 77:      40087          0          0          0          0          0          0          0     GICv3 352 Level     feab0000.i2c
 78:        187          0          0          0          0          0          0          0     GICv3 356 Level     fec90000.i2c
 79:    3064014          0          0          0          0          0          0          0     GICv3 187 Level     rkcifhw
 80:          0          0          0          0          0          0          0          0     GICv3 175 Level     rockchip-mipi-csi2-hw
 81:          0          0          0          0          0          0          0          0     GICv3 176 Level     rockchip-mipi-csi2-hw
 82:          0          0          0          0          0          0          0          0     GICv3 177 Level     rockchip-mipi-csi2-hw
 83:          0          0          0          0          0          0          0          0     GICv3 178 Level     rockchip-mipi-csi2-hw
 84:          0          0          0          0          0          0          0          0     GICv3 179 Level     rockchip-mipi-csi2-hw
 85:          0          0          0          0          0          0          0          0     GICv3 180 Level     rockchip-mipi-csi2-hw
 86:          0          0          0          0          0          0          0          0     GICv3 181 Level     rockchip-mipi-csi2-hw
 87:          0          0          0          0          0          0          0          0     GICv3 182 Level     rockchip-mipi-csi2-hw
 88:          0          0          0          0          0          0          0          0     GICv3 183 Level     rockchip-mipi-csi2-hw
 89:          0          0          0          0          0          0          0          0     GICv3 184 Level     rockchip-mipi-csi2-hw
 90:          0          0          0          0          0          0          0          0     GICv3 185 Level     rockchip-mipi-csi2-hw
 91:          0          0          0          0          0          0          0          0     GICv3 186 Level     rockchip-mipi-csi2-hw
 92:    3064014          0          0          0          0          0          0          0     GICv3 163 Level     rkisp_hw
 93:    1531987          0          0          0          0          0          0          0     GICv3 165 Level     rkisp_hw
 94:          0          0          0          0          0          0          0          0     GICv3 166 Level     rkisp_hw
 95:      85157          0          0          0          0          0          0          0     GICv3 235 Level     dw-mci
 96:          0          0          0          0          0          0          0          0     GICv3 430 Level     fec10000.saradc
 97:          0          0          0          0          0          0          0          0     GICv3 217 Level     i2s
 98:          0          0          0          0          0          0          0          0     GICv3 212 Level     i2s
 99:          0          0          0          0          0          0          0          0     GICv3 148 Level     rga2
100:          0          0          0          0          0          0          0          0     GICv3 151 Level     fdb50400.vdpu
101:          0          0          0          0          0          0          0          0     GICv3 152 Level     fdb50000.vepu
102:          0          0          0          0          0          0          0          0     GICv3 154 Level     fdba0000.jpege-core
103:          0          0          0          0          0          0          0          0     GICv3 156 Level     fdba4000.jpege-core
104:          0          0          0          0          0          0          0          0     GICv3 158 Level     fdba8000.jpege-core
105:          0          0          0          0          0          0          0          0     GICv3 160 Level     fdbac000.jpege-core
106:          0          0          0          0          0          0          0          0     GICv3 161 Level     fdb90000.jpegd
107:          0          0          0          0          0          0          0          0     GICv3 127 Level     fdc38100.rkvdec-core
108:          0          0          0          0          0          0          0          0     GICv3 129 Level     fdc48100.rkvdec-core
109:          0          0          0          0          0          0          0          0     GICv3 133 Level     fdbd0000.rkvenc-core
110:          0          0          0          0          0          0          0          0     GICv3 136 Level     fdbe0000.rkvenc-core
111:          0          0          0          0          0          0          0          0     GICv3 140 Level     fdc70000.av1d
113:    1322323          0          0          0          0          0          0          0     GICv3 124 Level     fb000000.gpu-mali
114:          1          0          0          0          0          0          0          0     GICv3 125 Level     fb000000.gpu-mali
115:    1324704          0          0          0          0          0          0          0     GICv3 126 Level     fb000000.gpu-mali
116:        110          0          0          0          0          0          0          0     GICv3 105 Level     dmc
117:         12          0          0          0          0          0          0          0     GICv3 237 Level     mmc0
IPI0:     11507      24796      22984      22872      30382      56776      31183      27267       Rescheduling interrupts
IPI1:    747075    3932227    1794461    1149139    1442524    1600198    3356632    4208007       Function call interrupts
IPI2:         0          0          0          0          0          0          0          0       CPU stop interrupts
IPI3:         0          0          0          0          0          0          0          0       CPU stop (for crash dump) interrupts
IPI4:   2136533    1534500     700881     495717     635048     515907    1293795    3986583       Timer broadcast interrupts
IPI5:   6512425    1457624     415943     289257    1667133     938907    2933097    1672701       IRQ work interrupts
IPI6:         0          0          0          0          0          0          0          0       CPU wake-up interrupts

In this erratic situation, can anyone spot who may cause the 100% CPU on ksoftirqd/0 ?
Any hints?

avaf · August 24, 2024, 6:38pm

Here is a dump of the interrupts while running the application in a normal situation:

   CPU0       CPU1       CPU2       CPU3       CPU4       CPU5       CPU6       CPU7       
  9:          0          0          0          0          0          0          0          0     GICv3  25 Level     vgic
 11:          0          0          0          0          0          0          0          0     GICv3  30 Level     kvm guest ptimer
 12:          0          0          0          0          0          0          0          0     GICv3  27 Level     kvm guest vtimer
 13:     703597     241575     187639     144569     220364     422930     457983     430534     GICv3  26 Level     arch_timer
 14:     482137     227103     180192     116310     244857     892726     852248     789643     GICv3 321 Level     rk_timer
 20:          0          0          0          0          0          0          0          0     GICv3 455 Edge      debug-signal
 21:          0          0          0          0          0          0          0          0     GICv3 365 Level     debug
 22:          0          0          0          0          0          0          0          0     GICv3 429 Level     rockchip_thermal
 23:          0          0          0          0          0          0          0          0     GICv3  23 Level     arm-pmu
 24:          0          0          0          0          0          0          0          0     GICv3 425 Level     rockchip_usb2phy
 25:          1          0          0          0          0          0          0          0     GICv3 423 Level     rockchip_usb2phy
 26:          2          0          0          0          0          0          0          0     GICv3 424 Level     rockchip_usb2phy
 29:         10          0          0          0          0          0          0          0     GICv3 118 Level     fea10000.dma-controller
 30:          0          0          0          0          0          0          0          0     GICv3 119 Level     fea10000.dma-controller
 31:          0          0          0          0          0          0          0          0     GICv3 120 Level     fea30000.dma-controller
 32:          0          0          0          0          0          0          0          0     GICv3 121 Level     fea30000.dma-controller
 33:          5          0          0          0          0          0          0          0     GICv3 122 Level     fed10000.dma-controller
 34:          0          0          0          0          0          0          0          0     GICv3 123 Level     fed10000.dma-controller
 35:          0          0          0          0          0          0          0          0     GICv3 142 Level     fdab9000.iommu, fdab0000.npu
 36:          0          0          0          0          0          0          0          0     GICv3 143 Level     fdab9000.iommu, fdab0000.npu
 37:          0          0          0          0          0          0          0          0     GICv3 144 Level     fdab9000.iommu, fdab0000.npu
 38:          0          0          0          0          0          0          0          0     GICv3 150 Level     fdb50800.iommu
 39:          0          0          0          0          0          0          0          0     GICv3 146 Level     fdb60f00.iommu, rga3_core0
 40:          0          0          0          0          0          0          0          0     GICv3 147 Level     fdb70f00.iommu, rga3_core1
 41:          0          0          0          0          0          0          0          0     GICv3 162 Level     fdb90480.iommu
 42:          0          0          0          0          0          0          0          0     GICv3 153 Level     fdba0800.iommu
 43:          0          0          0          0          0          0          0          0     GICv3 155 Level     fdba4800.iommu
 44:          0          0          0          0          0          0          0          0     GICv3 157 Level     fdba8800.iommu
 45:          0          0          0          0          0          0          0          0     GICv3 159 Level     fdbac800.iommu
 46:          0          0          0          0          0          0          0          0     GICv3 149 Level     fdbb0800.iommu, fdbb0000.iep
 47:          0          0          0          0          0          0          0          0     GICv3 131 Level     fdbdf000.iommu
 48:          0          0          0          0          0          0          0          0     GICv3 132 Level     fdbdf000.iommu
 49:          0          0          0          0          0          0          0          0     GICv3 134 Level     fdbef000.iommu
 50:          0          0          0          0          0          0          0          0     GICv3 135 Level     fdbef000.iommu
 51:          0          0          0          0          0          0          0          0     GICv3 128 Level     fdc38700.iommu
 52:          0          0          0          0          0          0          0          0     GICv3 130 Level     fdc48700.iommu
 53:          0          0          0          0          0          0          0          0     GICv3 141 Level     fdca0000.iommu
 54:          0          0          0          0          0          0          0          0     GICv3 164 Level     fdcb7f00.iommu
 55:          0          0          0          0          0          0          0          0     GICv3 145 Level     fdce0800.iommu
 56:     827354          0          0          0          0          0          0          0     GICv3 188 Level     fdd97e00.iommu, fdd90000.vop
 57:          0          0          0          0          0          0          0          0     GICv3 392 Level     dw-hdmi-qp-hpd
 58:          0          0          0          0          0          0          0          0     GICv3 201 Level     fde80000.hdmi
 59:          0          0          0          0          0          0          0          0     GICv3 202 Level     dw-hdmi-qp-cec
 60:          0          0          0          0          0          0          0          0     GICv3 203 Level     fde80000.hdmi
 61:        271          0          0          0          0          0          0          0     GICv3 204 Level     fde80000.hdmi
 62:     505908          0          0          0          0          0          0          0     GICv3 360 Level     feb20000.spi
 63:          0          0          0          0          0          0          0          0  rockchip_gpio_irq   7 Level     rk806
 64:          0          0          0          0          0          0          0          0     rk806   0 Edge      rk805_pwrkey_fall
 65:          0          0          0          0          0          0          0          0     rk806   1 Edge      rk805_pwrkey_rise
 66:          0          0          0          0          0          0          0          0     rk806   7 Level     rk806_vb_low
 67:     333768          0          0          0          0          0          0          0     GICv3 266 Level     eth0
 68:          0          0          0          0          0          0          0          0     GICv3 265 Level     eth0
 69:          0          0          0          0          0          0          0          0     GICv3 252 Level     xhci-hcd:usb1
 70:          0          0          0          0          0          0          0          0     GICv3 254 Level     xhci-hcd:usb7
 71:       8425          0          0          0          0          0          0          0     GICv3 247 Level     ehci_hcd:usb3
 72:          0          0          0          0          0          0          0          0     GICv3 250 Level     ehci_hcd:usb5
 73:          0          0          0          0          0          0          0          0     GICv3 248 Level     ohci_hcd:usb4
 74:          0          0          0          0          0          0          0          0     GICv3 251 Level     ohci_hcd:usb6
 75:     107152          0          0          0          0          0          0          0     GICv3 349 Level     fd880000.i2c
 76:         58          0          0          0          0          0          0          0     GICv3 351 Level     feaa0000.i2c
 77:       2775          0          0          0          0          0          0          0     GICv3 352 Level     feab0000.i2c
 78:        187          0          0          0          0          0          0          0     GICv3 356 Level     fec90000.i2c
 79:     826819          0          0          0          0          0          0          0     GICv3 187 Level     rkcifhw
 80:          0          0          0          0          0          0          0          0     GICv3 175 Level     rockchip-mipi-csi2-hw
 81:          0          0          0          0          0          0          0          0     GICv3 176 Level     rockchip-mipi-csi2-hw
 82:          0          0          0          0          0          0          0          0     GICv3 177 Level     rockchip-mipi-csi2-hw
 83:          0          0          0          0          0          0          0          0     GICv3 178 Level     rockchip-mipi-csi2-hw
 84:          0          0          0          0          0          0          0          0     GICv3 179 Level     rockchip-mipi-csi2-hw
 85:          0          0          0          0          0          0          0          0     GICv3 180 Level     rockchip-mipi-csi2-hw
 86:          0          0          0          0          0          0          0          0     GICv3 181 Level     rockchip-mipi-csi2-hw
 87:          0          0          0          0          0          0          0          0     GICv3 182 Level     rockchip-mipi-csi2-hw
 88:          0          0          0          0          0          0          0          0     GICv3 183 Level     rockchip-mipi-csi2-hw
 89:          0          0          0          0          0          0          0          0     GICv3 184 Level     rockchip-mipi-csi2-hw
 90:          0          0          0          0          0          0          0          0     GICv3 185 Level     rockchip-mipi-csi2-hw
 91:          0          0          0          0          0          0          0          0     GICv3 186 Level     rockchip-mipi-csi2-hw
 92:     826819          0          0          0          0          0          0          0     GICv3 163 Level     rkisp_hw
 93:     413409          0          0          0          0          0          0          0     GICv3 165 Level     rkisp_hw
 94:          0          0          0          0          0          0          0          0     GICv3 166 Level     rkisp_hw
 95:      17313          0          0          0          0          0          0          0     GICv3 235 Level     dw-mci
 96:          0          0          0          0          0          0          0          0     GICv3 430 Level     fec10000.saradc
 97:          0          0          0          0          0          0          0          0     GICv3 217 Level     i2s
 98:          0          0          0          0          0          0          0          0     GICv3 212 Level     i2s
 99:          0          0          0          0          0          0          0          0     GICv3 148 Level     rga2
100:          0          0          0          0          0          0          0          0     GICv3 151 Level     fdb50400.vdpu
101:          0          0          0          0          0          0          0          0     GICv3 152 Level     fdb50000.vepu
102:          0          0          0          0          0          0          0          0     GICv3 154 Level     fdba0000.jpege-core
103:          0          0          0          0          0          0          0          0     GICv3 156 Level     fdba4000.jpege-core
104:          0          0          0          0          0          0          0          0     GICv3 158 Level     fdba8000.jpege-core
105:          0          0          0          0          0          0          0          0     GICv3 160 Level     fdbac000.jpege-core
106:          0          0          0          0          0          0          0          0     GICv3 161 Level     fdb90000.jpegd
107:          0          0          0          0          0          0          0          0     GICv3 127 Level     fdc38100.rkvdec-core
108:          0          0          0          0          0          0          0          0     GICv3 129 Level     fdc48100.rkvdec-core
109:          0          0          0          0          0          0          0          0     GICv3 133 Level     fdbd0000.rkvenc-core
110:          0          0          0          0          0          0          0          0     GICv3 136 Level     fdbe0000.rkvenc-core
111:          0          0          0          0          0          0          0          0     GICv3 140 Level     fdc70000.av1d
113:    2519418          0          0          0          0          0          0          0     GICv3 124 Level     fb000000.gpu-mali
114:          1          0          0          0          0          0          0          0     GICv3 125 Level     fb000000.gpu-mali
115:    2677636          0          0          0          0          0          0          0     GICv3 126 Level     fb000000.gpu-mali
116:          7          0          0          0          0          0          0          0     GICv3 105 Level     dmc
117:         12          0          0          0          0          0          0          0     GICv3 237 Level     mmc0
IPI0:      1615       5811      10614       8586      44707       7326       4844       3834       Rescheduling interrupts
IPI1:   1324855    2042674    1004518     506877    1130234    1140015    1436714    1486825       Function call interrupts
IPI2:         0          0          0          0          0          0          0          0       CPU stop interrupts
IPI3:         0          0          0          0          0          0          0          0       CPU stop (for crash dump) interrupts
IPI4:    219117     109756      52962      35954      46225     212396     217062     216068       Timer broadcast interrupts
IPI5:    683911     429626     194461      93660     504731     514157     530913     516489       IRQ work interrupts
IPI6:         0          0          0          0          0          0          0          0       CPU wake-up interrupts
Err:          0

avaf · August 25, 2024, 1:40pm

After more than 24 hours of streaming video and some analysis, i think i found the culprit, RGA3.
I see a lot of activities on eth0 but when i get 100% CPU on ksoftirqd/0 there is rga3 involved:

100% CPU:
39: 1342415 0 0 0 0 0 0 0 GICv3 146 Level fdb60f00.iommu, rga3_core0

0% CPU:
39: 0 0 0 0 0 0 0 0 GICv3 146 Level fdb60f00.iommu, rga3_core0

While rendering the image on the screen with DRM 0% CPU:

DEBUG: New DRM FB (226): 1920x1080, stride 7680 from BO 0xaaaade5596b0
DEBUG: New DRM FB (235): 1920x1080, stride 7680 from BO 0xaaaade5593f0
DEBUG: New DRM FB (236): 1920x1080, stride 7680 from BO 0xaaaade560810

Also with Weston, i have this load:

num of scheduler = 3
================= load ==================
scheduler[0]: rga3_core0
	 load = 0%
-----------------------------------
scheduler[1]: rga3_core1
	 load = 0%
-----------------------------------
scheduler[2]: rga2
	 load = 0%
-----------------------------------

willy · August 26, 2024, 2:59am

You should use “perf top” for this, it should indicate where the CPU time is spent. /proc/interrupts won’t give you any hint because ksoftirqd’s principle is to work in polling mode, so when it runs, any similar interrupt that fires automatically disables itself till ksoftirqd is done, thus you can run totally irq-less if the CPU remains busy. And I’m not aware of any observable counter of events that keep ksoftirqd running.

avaf · September 4, 2024, 10:08pm

I tried hard to reproduce it without success after i recompiled everything with GCC 12.3, from kernel to media.

Suddenly it happened again while i was testing a camera sensor so the csi kernel was involved.

Here is the perf top, Do you have any clue?

   PerfTop:    4203 irqs/sec  kernel:97.6%  exact:  0.0% lost: 0/0 drop: 0/0 [4000Hz cycles],  (all, 8 CPUs)
-------------------------------------------------------------------------------

    28.87%  [kernel]          [k] __do_softirq
    24.69%  [kernel]          [k] tasklet_action_common.constprop.0
    14.84%  [kernel]          [k] wake_up_var
     8.97%  [kernel]          [k] rcu_softirq_qs
     5.86%  [kernel]          [k] rcu_qs
     4.59%  [kernel]          [k] run_ksoftirqd
     4.21%  [kernel]          [k] tasklet_action
     4.11%  [kernel]          [k] tasklet_unlock
     0.76%  [kernel]          [k] smpboot_thread_fn
     0.54%  [kernel]          [k] __cond_resched
     0.52%  [kernel]          [k] kthread_should_stop
     0.48%  [kernel]          [k] rcu_all_qs
     0.46%  [kernel]          [k] kthread_should_park
     0.20%  [kernel]          [k] ksoftirqd_should_run
     0.05%  [kernel]          [k] finish_task_switch.isra.0
     0.04%  [kernel]          [k] cpuidle_enter_state
     0.02%  perf              [.] 0x00000000000d9500
     0.02%  perf              [.] 0x00000000001aef84
     0.01%  [kernel]          [k] update_blocked_averages

actual top output:

Tasks: 205 total,   2 running, 203 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  1.5 sy,  0.0 ni, 87.4 id,  0.0 wa,  0.0 hi, 11.1 si,  0.0 st
MiB Mem :   1973.6 total,   1444.9 free,    213.0 used,    315.7 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.   1706.3 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                   
     13 root      20   0       0      0      0 R 100.0   0.0 113:27.04 ksoftirqd/0                                                                               
   6524 rock      20   0    7388   3212   2616 R   0.7   0.2   0:02.53 top                                                                                       
      1 root      20   0  166016  10152   7396 S   0.0   0.5   0:01.50 systemd                                                                                   
      2 root      20   0       0      0      0 S   0.0   0.0   0:00.02 kthreadd                                                                                  
      3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp                                                                                    
      4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp                                                                                
      5 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 slub_flushwq                                                                              
      6 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 netns                                                                                     
     10 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq                                                                              
     11 root      20   0       0      0      0 I   0.0   0.0   0:00.00 rcu_tasks_rude_kthread                                                                    
     12 root      20   0       0      0      0 I   0.0   0.0   0:00.00 rcu_tasks_trace_kthread                                                                   
     14 root      20   0       0      0      0 I   0.0   0.0   0:01.45 rcu_sched                                                                                 
     15 root      rt   0       0      0      0 S   0.0   0.0   0:00.77 migration/0                                                                               
     16 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/0                                                                                   
     17 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/1                                                                                   
     18 root      rt   0       0      0      0 S   0.0   0.0   0:00.78 migration/1                                                                               
     19 root      20   0       0      0      0 S   0.0   0.0   0:00.01 ksoftirqd/1

forgot to mention dmesg:

[ 4124.635705] usb 4-1.3: USB disconnect, device number 8
[ 4124.942817] usb 4-1.3: new high-speed USB device number 9 using ehci-platform
[ 4125.140327] usb 4-1.3: New USB device found, idVendor=a69c, idProduct=8d80, bcdDevice= 1.00
[ 4125.140336] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 4125.140342] usb 4-1.3: Product: AIC Wlan
[ 4125.140347] usb 4-1.3: Manufacturer: aicsemi
[ 4125.140351] usb 4-1.3: SerialNumber: 20220103
[ 5496.539710] usb 4-1.3: USB disconnect, device number 9
[ 5496.845009] usb 4-1.3: new high-speed USB device number 10 using ehci-platform
[ 5497.042576] usb 4-1.3: New USB device found, idVendor=a69c, idProduct=8d80, bcdDevice= 1.00
[ 5497.042586] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 5497.042592] usb 4-1.3: Product: AIC Wlan
[ 5497.042597] usb 4-1.3: Manufacturer: aicsemi
[ 5497.042601] usb 4-1.3: SerialNumber: 20220103
[ 6545.474930] rk_gmac-dwmac fe1c0000.ethernet eth0: Link is Down
[ 6571.823379] rk_gmac-dwmac fe1c0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 6623.500167] rk_gmac-dwmac fe1c0000.ethernet eth0: Link is Down
[ 6668.088187] rk_gmac-dwmac fe1c0000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 6868.699710] usb 4-1.3: USB disconnect, device number 10
[ 6869.005924] usb 4-1.3: new high-speed USB device number 11 using ehci-platform
[ 6869.203454] usb 4-1.3: New USB device found, idVendor=a69c, idProduct=8d80, bcdDevice= 1.00
[ 6869.203464] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 6869.203471] usb 4-1.3: Product: AIC Wlan
[ 6869.203475] usb 4-1.3: Manufacturer: aicsemi
[ 6869.203479] usb 4-1.3: SerialNumber: 20220103
[ 8240.859708] usb 4-1.3: USB disconnect, device number 11
[ 8241.165433] usb 4-1.3: new high-speed USB device number 12 using ehci-platform
[ 8241.362953] usb 4-1.3: New USB device found, idVendor=a69c, idProduct=8d80, bcdDevice= 1.00
[ 8241.362964] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 8241.362969] usb 4-1.3: Product: AIC Wlan
[ 8241.362974] usb 4-1.3: Manufacturer: aicsemi
[ 8241.362978] usb 4-1.3: SerialNumber: 20220103
[ 9070.933660] FAT-fs (mmcblk1p1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive!
[ 9070.935487] FAT-fs (mmcblk1p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[ 9072.359905] perf: interrupt took too long (2512 > 2500), lowering kernel.perf_event_max_sample_rate to 79500
[ 9074.802243] perf: interrupt took too long (3167 > 3140), lowering kernel.perf_event_max_sample_rate to 63000
[ 9078.810764] perf: interrupt took too long (3960 > 3958), lowering kernel.perf_event_max_sample_rate to 50400
[ 9613.275711] usb 4-1.3: USB disconnect, device number 12
[ 9613.580708] usb 4-1.3: new high-speed USB device number 13 using ehci-platform
[ 9613.778200] usb 4-1.3: New USB device found, idVendor=a69c, idProduct=8d80, bcdDevice= 1.00
[ 9613.778209] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 9613.778215] usb 4-1.3: Product: AIC Wlan
[ 9613.778220] usb 4-1.3: Manufacturer: aicsemi
[ 9613.778224] usb 4-1.3: SerialNumber: 20220103

wlan0 is gone!

willy · September 5, 2024, 3:35am

It looks like an IRQ storm but without that many IRQs (4k/s is low). Apparently there’s no handler for that IRQ given that I’m not seeing anything obvious in that stack that suggests any driver for example, all visible functions are task wakeups and such stuff on the softirq delivery path. It’s as if an IRQ was not handled and for some reason was kept ringing with nobody answering, but I don’t know how this is possible. It might possibly be the result of one of the numerous changes in Rockchip’s FrankenKernel. Maybe one of their drivers incorrectly registers an IRQ and causes this as a side effect, but that’s very hard to say. Maybe it would be worth reporting this to the issue tracker of the repository where you picked the kernel. I don’t know if issues are being looked at, but maybe it could help them find the problem and fix it, because your report it quite detailed.

avaf · September 5, 2024, 12:03pm

I think i agree with you.

Something interesting happened, without rebooting i fired a build process (wanted to rebuild the aic8800 driver) and went to sleep, when i got back to the board it seemed to be ok now:

   PerfTop:      91 irqs/sec  kernel:60.4%  exact:  0.0% lost: 0/0 drop: 0/0 [4000Hz cycles],  (all, 8 CPUs)
-------------------------------------------------------------------------------

     9.03%  [kernel]          [k] cpuidle_enter_state
     4.97%  [kernel]          [k] finish_task_switch.isra.0
     3.24%  [kernel]          [k] _raw_spin_unlock_irqrestore
     2.30%  perf              [.] 0x00000000000ceef0
     1.52%  [kernel]          [k] __pi_clear_page
     1.34%  [kernel]          [k] _raw_spin_unlock_irq
     1.26%  [kernel]          [k] kallsyms_expand_symbol.constprop.0
     1.09%  [kernel]          [k] __do_softirq
     0.99%  [kernel]          [k] tick_nohz_idle_exit
     0.88%  [kernel]          [k] next_uptodate_page
     0.80%  [kernel]          [k] unmap_page_range
     0.65%  [kernel]          [k] update_blocked_averages
     0.63%  [kernel]          [k] do_raw_spin_lock
     0.62%  [kernel]          [k] __pi_copy_page
     0.57%  [kernel]          [k] kmem_cache_alloc
     0.56%  [kernel]          [k] number
     0.53%  perf              [.] 0x00000000000cef18
     0.52%  [kernel]          [k] format_decode
     0.50%  [kernel]          [k] vsnprintf
exiting.

and dmesg log:

[44657.509139] FAT-fs (mmcblk1p1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive!
[44657.529342] perf: interrupt took too long (2508 > 2500), lowering kernel.perf_event_max_sample_rate to 79500
[44658.990096] perf: interrupt took too long (3161 > 3135), lowering kernel.perf_event_max_sample_rate to 63000
[44659.181754] perf: interrupt took too long (3971 > 3951), lowering kernel.perf_event_max_sample_rate to 50100
[44659.828436] perf: interrupt took too long (5017 > 4963), lowering kernel.perf_event_max_sample_rate to 39600
[44664.911573] perf: interrupt took too long (6281 > 6271), lowering kernel.perf_event_max_sample_rate to 31800
[44714.701483] perf: interrupt took too long (7861 > 7851), lowering kernel.perf_event_max_sample_rate to 25200
[44737.861120] perf: interrupt took too long (9839 > 9826), lowering kernel.perf_event_max_sample_rate to 20100

i found this suspicious:
FAT-fs (mmcblk1p1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive!

Looks like FS was unmounted and mounted, but no log for ‘mounting process’…
Anyway, re-installing the aicsemi driver and checking again…

avaf · September 7, 2024, 3:14pm

I’m able to reproduce the issue now, but I’m not sure i can fix it.
While testing the driver, if i got an exception passing a ‘wrong’ parameter, let’s say if kernel throws an “ioctl: Invalid argument”, this triggers that thing. If i revert the parameter without rebooting the ksoftirqd/0 100% CPU returns to a normal state.

willy · September 8, 2024, 11:30am

Since you have a reproducer, you should file an issue at Radxa’s kernel or Rockchip’s kernel on github. Only once those who patch the kernels are aware of the trouble (with a reproducer), there is a hope that someone looks at it and tries to fix it.

The situation with the BSP kernel is exactly why I’m really fed up with SoC vendors continuing to distribute such crap: when you face such a bug, there’s no way for the end user to report that to the upstream kernel, since it very likely comes from the myriad of patches the vendor applied. Then only a few eyes are susceptible to look at your issue while with a standard kernel everyone could. And that prevents you from testing more recent kernels. Very annoying…