Sample Header Ad - 728x90

Need help to understand a kernel "deadlock" in armhf kernel 5.4

0 votes
0 answers
65 views
I'm struggling to understand a condition that occurs rarely (MTBF measured in weeks to months), but results in a fatal kernel lockup when it does. The environment is kernel 5.4.0, running on a dual-core ARM A9 32-bit (armhf) processor in an AMD/Xilinx Zynq 7020 SoC. I've been able to examine stack traces on two failed devices using the Xilinx Vitis system debugger. In both cases, both cores were waiting for (attempting to lock) the same spinlock. The spinlock is the pi_lock member of the struct task_struct structure associated with a threaded IRQ handler. Core #0 is running the idle process, responding to an interrupt, attempting to wake up the IRQ handler thread. Core #1 is reading the /proc//stat sysfs pseudofile associated with the IRQ handler thread (while reading all of the sysfs pseudofiles of the form /proc//stat on behalf of pidof, probably at the request of sessionclean, invoked by apache2). The interrupt being handled on one device is for the BQ25890 battery charger (asserted ~zero to 10 times per second, and on the other device, for a custom kernel module (~100/sec.). Both interrupts use the default primary IRQ handler. The current hypothesis is that that core #0 got stuck first, followed some time later by core #1, rather than both occurring simultaneously, but this is speculative. Stack traces for the two cores and threaded IRQ handler source for one of the devices are below. **Questions** Is there enough information in the stack traces to provide a clue as to what went wrong? If so, what went wrong? If not, what additional information is needed? One of the devices is still available, and some (not all) variables can be interrogated. Is the fact that interrupts are disabled (cpsr.i == 1 for both cores) significant? Please note that because of the extremely long time between failures, black-box testing techniques - that is, making changes in order to observe the result - are not practical. **ARM Cortex-A9 MPCore #0 (Suspended)** 0x80165d68: ./include/linux/compiler.h, line 199 0x80165d68 arch_spin_lock(): .../arch/arm/include/asm/spinlock.h, line 75 0x8076f774: ./include/linux/spinlock.h, line 193 0x8076f774: ...include/linux/spinlock_api_smp.h, line 119 0x8076f774 _raw_spin_lock_irqsave(): kernel/locking/spinlock.c, line 159 0x8014a394 try_to_wake_up(): kernel/sched/core.c, line 2551 0x8014a724 wake_up_process(): kernel/sched/core.c, line 2667 0x8016f600 __irq_wake_thread(): kernel/irq/handle.c, line 134 0x8016f820 __handle_irq_event_percpu(): kernel/irq/handle.c, line 167 0x8016f888 handle_irq_event_percpu(): kernel/irq/handle.c, line 189 0x8016f924 handle_irq_event(): kernel/irq/handle.c, line 206 0x80174230 handle_level_irq(): kernel/irq/chip.c, line 650 0x8016e808: ./include/linux/irqdesc.h, line 156 0x8016e808 generic_handle_irq(): kernel/irq/irqdesc.c, line 644 0x80447a20: drivers/gpio/gpio-zynq.c, line 632 0x80447a20 zynq_gpio_irqhandler(): drivers/gpio/gpio-zynq.c, line 661 0x8016e808: ./include/linux/irqdesc.h, line 156 0x8016e808 generic_handle_irq(): kernel/irq/irqdesc.c, line 644 0x8016eec4 __handle_domain_irq(): kernel/irq/irqdesc.c, line 681 0x80102300: ./include/linux/irqdesc.h, line 174 0x80102300 gic_handle_irq(): drivers/irqchip/irq-gic.c, line 383 0x80101a70 __irq_svc(): arch/arm/kernel/entry-armv.S, line 212 0x805827c0 cpuidle_enter_state(): .../arch/arm/include/asm/irqflags.h, line 39 0x805829d8 cpuidle_enter(): drivers/cpuidle/cpuidle.c, line 344 0x8014ecf0: kernel/sched/idle.c, line 117 0x8014ecf0: kernel/sched/idle.c, line 201 0x8014ecf0 do_idle(): kernel/sched/idle.c, line 263 0x8014eeac cpu_startup_entry(): kernel/sched/idle.c, line 355 0x80769828 rest_init(): init/main.c, line 451 0x80c00b30 arch_call_rest_init(): init/main.c, line 572 0x80c00f78 start_kernel(): init/main.c, line 784 0x00000000 0x00000000 **The offending lock** lock arch_spinlock_t * {{slock=0x94449440, tickets={owner=0x9440, next=0x9444}}} slock u32 0x94449440 tickets struct __raw_tickets {owner=0x9440, next=0x9444} owner u16 0x9440 next u16 0x9444 **Threaded IRQ handler source** Note that this code does not appear in the call stacks, but is the code for the thread that core #0 is attempting to wake up. On one of the devices: static irqreturn_t bq25890_irq_handler_thread(int irq, void *private) { struct bq25890_device *bq = private; int ret; struct bq25890_state state; ret = bq25890_get_chip_state(bq, &state); if (ret lock); bq->state = state; mutex_unlock(&bq->lock); power_supply_changed(bq->charger); handled: return IRQ_HANDLED; } On the other device: static irqreturn_t core100_irq_handler( int irq, void* data ) { struct core100_drvdata* p_info; struct core100_block_header* next; unsigned long iflags; p_info = ( struct core100_drvdata* ) data; if ( ( p_info->state != state_reading ) && ( p_info->state != state_writing ) ) { return IRQ_HANDLED; } next = &p_info->current_block->next->header; next->count_at_pps = read_register( p_info->count_pps_register ); next->frc_at_pps = read_register( p_info->frc_pps_register ); next->count = adc_counter(); next->frc = free_running_counter(); spin_lock_irqsave( &p_info->state_lock, iflags ); p_info->dma_head += bytes_per_block( p_info ); if ( p_info->dma_head - p_info->dma_tail > bytes_per_buffer( p_info ) ) { p_info->dma_tail = p_info->dma_head - bytes_per_buffer( p_info ); } p_info->current_block = p_info->current_block->next; wake_up_interruptible( &p_info->wq ); spin_unlock_irqrestore( &p_info->state_lock, iflags ); return IRQ_HANDLED; } Kernel source: [struct task_struct] **ARM Cortex-A9 MPCore #1 (Suspended)** 0x80165d68: ./include/linux/compiler.h, line 199 0x80165d68 arch_spin_lock(): .../arch/arm/include/asm/spinlock.h, line 75 0x8076f774: ./include/linux/spinlock.h, line 193 0x8076f774: ...include/linux/spinlock_api_smp.h, line 119 0x8076f774 _raw_spin_lock_irqsave(): kernel/locking/spinlock.c, line 159 0x80148914 task_rq_lock(): kernel/sched/core.c, line 109 0x8014e22c: kernel/sched/cputime.c, line 281 0x8014e22c thread_group_cputime(): kernel/sched/cputime.c, line 326 0x8014e650 thread_group_cputime_adjusted(): kernel/sched/cputime.c, line 678 0x802ccb5c do_task_stat(): fs/proc/array.c, line 510 0x802cdaf4 proc_tgid_stat(): fs/proc/array.c, line 632 0x802c7c0c proc_single_show(): fs/proc/base.c, line 756 0x80281b18 seq_read(): fs/seq_file.c, line 229 0x8025dd1c __vfs_read(): fs/read_write.c, line 425 0x8025de60 vfs_read(): fs/read_write.c, line 461 0x8025e088 ksys_read(): fs/read_write.c, line 587 0x8025e0ec: fs/read_write.c, line 597 0x8025e0ec __se_sys_read(): fs/read_write.c, line 595 0x80101000 __idmap_text_end() 0x76e627e6 0x76edc616 Here's an alternative view, showing the calls stacks associated with their calling processes. "Swapper" is an archaic term for the idle process: Kernel 0 swapper/0 (Suspended), ARM Cortex-A9 MPCore #0 0x80165d68: ./include/linux/compiler.h, line 199 0x80165d68 arch_spin_lock(): .../arch/arm/include/asm/spinlock.h, line 75 0x8076f774: ./include/linux/spinlock.h, line 193 0x8076f774: ...include/linux/spinlock_api_smp.h, line 119 0x8076f774 _raw_spin_lock_irqsave(): kernel/locking/spinlock.c, line 159 11950 pidof 11950 (Suspended), ARM Cortex-A9 MPCore #1 0x80165d68: ./include/linux/compiler.h, line 199 0x80165d68 arch_spin_lock(): .../arch/arm/include/asm/spinlock.h, line 75 0x8076f774: ./include/linux/spinlock.h, line 193 0x8076f774: ...include/linux/spinlock_api_smp.h, line 119 0x8076f774 _raw_spin_lock_irqsave(): kernel/locking/spinlock.c, line 159 **RCU Configuration** # RCU Subsystem CONFIG_PREEMPT_RCU=y # CONFIG_RCU_EXPERT is not set CONFIG_SRCU=y CONFIG_TREE_SRCU=y CONFIG_TASKS_RCU=y CONFIG_RCU_STALL_COMMON=y CONFIG_RCU_NEED_SEGCBLIST=y # end of RCU Subsystem # RCU Debugging # CONFIG_RCU_PERF_TEST is not set # CONFIG_RCU_TORTURE_TEST is not set CONFIG_RCU_CPU_STALL_TIMEOUT=21 # CONFIG_RCU_TRACE is not set # CONFIG_RCU_EQS_DEBUG is not set # end of RCU Debugging **Kernel Thread Prioities** # ps -eo pid,tid,class,rtprio,ni,pri,wchan:14,comm | grep -E '(PID|bq25890|raw_dma)' PID TID CLS RTPRIO NI PRI WCHAN COMMAND 214 214 FF 50 - 90 irq_thread irq/59-bq25890_ 229 229 FF 50 - 90 irq_thread irq/60-raw_dma **Processor Status Registers** On at least one failed system, the interrupt disable bit is set on both processors. That seems wrong, although the fast interrupt disable bit is not set. If I set a breakpoint in arch_spin_lock() on a working system, the interrupt disable bit is not set. It would seem that the only way for the spinlock to be released is in response to an interrupt, since the active threads on both cores aren't going to do it. Core #0 cpsr 200f0193 537854355 n 0 0 Negative condition code flag z 0 0 Zero condition code flag c 1 1 Carry condition code flag v 0 0 Overflow condition code flag q 0 0 Cumulative saturation flag it 00 0 If-Then execution state bits j 0 0 Jazelle bit ge f 15 SIMD Greater than or Equal flags e 0 0 Endianness execution state bit a 1 1 Asynchronous abort disable bit i 1 1 Interrupt disable bit f 0 0 Fast interrupt disable bit t 0 0 Thumb execution state bit m 13 19 Mode field irq sp 80d94400 2161722368 lr 80101e20 2148539936 spsr 200f0193 537854355 n 0 0 Negative condition code flag z 0 0 Zero condition code flag c 1 1 Carry condition code flag v 0 0 Overflow condition code flag q 0 0 Cumulative saturation flag it 00 0 If-Then execution state bits j 0 0 Jazelle bit ge f 15 SIMD Greater than or Equal flags e 0 0 Endianness execution state bit a 1 1 Asynchronous abort disable bit i 1 1 Interrupt disable bit f 0 0 Fast interrupt disable bit t 0 0 Thumb execution state bit m 13 19 Mode field Core #1 cpsr 200f0093 537854099 n 0 0 Negative condition code flag z 0 0 Zero condition code flag c 1 1 Carry condition code flag v 0 0 Overflow condition code flag q 0 0 Cumulative saturation flag it 00 0 If-Then execution state bits j 0 0 Jazelle bit ge f 15 SIMD Greater than or Equal flags e 0 0 Endianness execution state bit a 0 0 Asynchronous abort disable bit i 1 1 Interrupt disable bit f 0 0 Fast interrupt disable bit t 0 0 Thumb execution state bit m 13 19 Mode field irq sp 80d94440 2161722432 lr 80101a00 2148538880 spsr 60030193 1610809747 n 0 0 Negative condition code flag z 1 1 Zero condition code flag c 1 1 Carry condition code flag v 0 0 Overflow condition code flag q 0 0 Cumulative saturation flag it 00 0 If-Then execution state bits j 0 0 Jazelle bit ge 3 3 SIMD Greater than or Equal flags e 0 0 Endianness execution state bit a 1 1 Asynchronous abort disable bit i 1 1 Interrupt disable bit f 0 0 Fast interrupt disable bit t 0 0 Thumb execution state bit m 13 19 Mode field
Asked by Omnia tu scis quod malum (1 rep)
Nov 24, 2023, 10:59 PM
Last activity: Nov 29, 2023, 05:49 PM