Цитата:

Many functions in the kernel sleep (ie. call schedule()) directly or indirectly: you can never call them while holding a spinlock, or with preemption disabled. This also means you need to be in user context: calling them from an interrupt is illegal.

Неделю достаточно трудоёмкой (в плане воспроизведения) отладки пришлось потрать по причинам:

1. Незнания информации из цитаты выше (компетентность? не, не слышал).
2. Наличия неявной блокировки в недрах ALSA при вызове колбека snd_pcm_ops::trigger().

Про второй пункт попадалась информация:

Run under stream lock

Этот самый “stream lock” обеспечивается семейством функций:

• snd_pcm_stream_lock()/snd_pcm_stream_unlock()
• snd_pcm_stream_lock_irq()/snd_pcm_stream_unlock_irq()
• snd_pcm_stream_lock_irqsave()/snd_pcm_stream_unlock_irqsave()

И вводит понятия: “atomic context” and “non-atomic context”.

Контекст определяется значением флага substream->pcm->nonatomic (bool snd_pcm::nonatomic).

Если не сказано иного, то там значение 0, или “atomic context”.

И этот самый контекст вляет на то, какой тип блокировки будет использоваться: mutex или spin lock.

По неудачному стечению обстоятельств в колбеке snd_pcm_ops::trigger() появился вызов cancel_delayed_work_sync(). А контекст был объявлен как “atomic”. И работать всё стало очень весело, в зависимости от того, куда какое нейтрино попадёт :)

Проявлялось по разному:

• случайные зависания при закрытии аудио устройства
• случайные зависания при перезагрузке (если устройство было открыто)

В терминал при этом вылетало такое:

Requesting system reboot
[   56.034544] watchdog: BUG: soft lockup - CPU#3 stuck for 23s! [init:7475]

А дальше вариции:

• Стектрейсы, например:

  [   52.084474] Modules linked in: sch_htb xlnx_sdi_audio regmap_mmio v_comp(O) v_scaler(O) v_process(O) snd_soc_xlnx_audio_formatter snd_soc_xlnx_i2s mali(O) xilinx_dp_card xilinx_dp_pcm xilinx_dp_codec snd_soc_tlv320aic3x pwm_cadence(O) max6966_keys(O) max6966_backlight(O) max6966_leds(O) max6966_mfd(O) fbili9341(O) it666x(O) xilinx_hdmi_rx(O) xilinx_vphy(O) xilinx_sdirxss u_dma_buf(O) uio_pdrv_genirq dmaproxy(O) al5d(O) xlnx_vcu_clk al5e(O) allegro(O) xlnx_vcu xlnx_vcu_core xlnx_pl_snd_card snd_soc_core snd_pcm_dmaengine snd_pcm snd_timer snd soundcore xilinx_vpss_scaler xilinx_video videobuf2_v4l2 v4l2_fwnode videobuf2_common videobuf2_dma_contig videobuf2_memops videodev media
  [   52.144543] CPU: 1 PID: 6938 Comm: init Tainted: G           O        4.19.0-xilinx-v2019.2 #83
  [   52.153054] Hardware name: Epiphan X3 (DT)
  [   52.157136] pstate: 20000005 (nzCv daif -PAN -UAO)
  [   52.161915] pc : smp_call_function_single+0x140/0x170
  [   52.166952] lr : smp_call_function_single+0x110/0x170
  [   52.171985] sp : ffffff802e0f3bb0
  [   52.175283] x29: ffffff802e0f3bb0 x28: ffffffc03d3eac00 
  [   52.180586] x27: 0000000000000002 x26: ffffff8008b887c8 
  [   52.185881] x25: ffffff8008b9a9a0 x24: ffffff8008125800 
  [   52.191185] x23: 0000000000000002 x22: ffffff8008b9a9c0 
  [   52.196480] x21: ffffffbebffc7b58 x20: ffffff8008b88548 
  [   52.201774] x19: ffffff802e0f3be0 x18: 0000000000000000 
  [   52.207069] x17: 0000000000000000 x16: 0000000000000000 
  [   52.212364] x15: 0000000000000000 x14: 0000000000000000 
  [   52.217659] x13: 0000000000000000 x12: 0000000000000000 
  [   52.222953] x11: 0000000000000000 x10: 0000000000000000 
  [   52.228248] x9 : 0000000000000000 x8 : 0000000000000000 
  [   52.233543] x7 : 0000000000000000 x6 : ffffff802e0f3be0 
  [   52.238838] x5 : ffffff802e0f3be0 x4 : 0000000000000004 
  [   52.244133] x3 : ffffff802e0f3bf8 x2 : 0000000000000000 
  [   52.249428] x1 : 0000000000000003 x0 : 0000000000000000 
  [   52.254723] Call trace:
  [   52.257155]  smp_call_function_single+0x140/0x170
  [   52.261844]  perf_event_exit_cpu_context+0x84/0xe0
  [   52.266624]  perf_reboot+0x2c/0x60
  [   52.270011]  notifier_call_chain+0x54/0x90
  [   52.274099]  blocking_notifier_call_chain+0x54/0x80
  [   52.278960]  kernel_restart_prepare+0x1c/0x40
  [   52.283299]  kernel_restart+0x14/0x60
  [   52.286945]  __se_sys_reboot+0xd4/0x1f0
  [   52.290764]  __arm64_sys_reboot+0x18/0x20
  [   52.294758]  el0_svc_handler+0xc8/0x120
  [   52.298584]  el0_svc+0x8/0xc
  

• Периодические репорты:

  [   62.477485] BUG: workqueue lockup - pool cpus=2 node=0 flags=0x0 nice=0 stuck for 36s!
  

В общем, рекомендую к внимательному чтению:

• Unreliable Guide To Locking

Только не смотрите на год :)

И перед тем, как ставить msleep()/mutex_lock()/etc, изучите, кто вызывает этот код, есть ли там блокировка и какая. А если код ваш, посмотрите на шпаргалку по выбору типа блокировки.

PS а если полезно под рукой иметь глоссарий. В частности он объяснил мне, что это за функции с суффиксом _bh и что такое tasklet.