Re: [PATCH v4] drm/bridge: dw-hdmi-qp: Guard clear_audio_infoframe when PHY is down

[Igor Paunovic <royalnet026@gmail.com>]

Hi Frank, Cristian,

Independent hit of the same crash, in case it helps get this one moving
again.

Board: Rockchip RK3588, Orange Pi 5 Plus. Kernel: 7.2.0-rc7 with the
Collabora dw-hdmi-qp HDMI 2.1/FRL work on top (so not plain mainline, but
the audio shutdown path is the same code). Userspace: PipeWire/WirePlumber.

At that boot the HDMI link never came up (the sink did not answer SCDC),
so every snd_soc_dai_prepare() failed with -ENODEV, and about five seconds
later WirePlumber closing the PCM took the same path your patch guards:

  snd_pcm_release -> hdmi_codec_shutdown
    -> drm_connector_hdmi_audio_shutdown
    -> dw_hdmi_qp_audio_disable
    -> drm_atomic_helper_connector_hdmi_clear_audio_infoframe
    -> dw_hdmi_qp_bridge_clear_audio_infoframe
    -> regmap_update_bits (read) -> SError, panic

Serial console excerpt (7.2.0-rc7, tmds_char_rate was 0 at that point):

[   16.597316] hdmi-audio-codec hdmi-audio-codec.7.auto: ASoC error (-19): at snd_soc_dai_prepare() on i2s-hifi   (x4)
[   16.601847] SError Interrupt on CPU5, code 0x00000000be000011 -- SError
[   16.601852] CPU: 5 UID: 112 PID: 2821 Comm: wireplumber Tainted: G   M       OE       7.2.0-rc7-rk3588-igor-claude-hdr2+ #10 PREEMPT(lazy)
[   16.601862] pc : regmap_mmio_read32le+0x38/0xf0
[   16.601867] lr : regmap_mmio_read+0x50/0x98
[...]
[   16.601903] Call trace:
[   16.601904]  show_stack+0x24/0x50 (C)
[   16.601908]  dump_stack_lvl+0xe0/0x140
[   16.601912]  dump_stack+0x1c/0x38
[   16.601915]  vpanic+0x4e8/0x5b0
[   16.601919]  panic+0x6c/0x78
[   16.601921]  nmi_panic+0x8c/0x98
[   16.601924]  arm64_serror_panic+0x7c/0x98
[   16.601927]  arm64_is_fatal_ras_serror+0xa8/0xb0
[   16.601930]  do_serror+0x3c/0x78
[   16.601932]  el1h_64_error_handler+0x40/0x80
[   16.601937]  el1h_64_error+0x84/0x88
[   16.601938]  regmap_mmio_read32le+0x38/0xf0 (P)
[   16.601941]  regmap_mmio_read+0x50/0x98
[   16.601943]  _regmap_bus_reg_read+0x68/0xd0
[   16.601947]  _regmap_read+0x80/0x2a8
[   16.601950]  _regmap_update_bits+0x13c/0x1e0
[   16.601953]  regmap_update_bits_base+0x70/0xd0
[   16.601956]  dw_hdmi_qp_bridge_clear_audio_infoframe+0x3c/0x78 [dw_hdmi_qp]
[   16.601964]  drm_bridge_connector_clear_audio_infoframe+0x2c/0x68 [drm_display_helper]
[   16.601993]  clear_infoframe+0x5c/0x128 [drm_display_helper]
[   16.602016]  drm_atomic_helper_connector_hdmi_clear_audio_infoframe+0x70/0x110 [drm_display_helper]
[   16.602039]  dw_hdmi_qp_audio_disable+0x28/0x108 [dw_hdmi_qp]
[   16.602042]  drm_bridge_connector_audio_shutdown+0x38/0x80 [drm_display_helper]
[   16.602065]  drm_connector_hdmi_audio_shutdown+0x28/0x50 [drm_display_helper]
[   16.602086]  hdmi_codec_shutdown+0x68/0xb0 [snd_soc_hdmi_codec]
[   16.602091]  snd_soc_dai_shutdown+0x60/0xe0 [snd_soc_core]
[   16.602123]  soc_pcm_clean.isra.0+0x5c/0x1f8 [snd_soc_core]
[   16.602151]  soc_pcm_close+0x40/0x80 [snd_soc_core]
[   16.602177]  snd_pcm_release_substream.part.0+0x48/0xf0 [snd_pcm]
[   16.602193]  snd_pcm_release+0x68/0x110 [snd_pcm]
[   16.602205]  __fput+0xe4/0x340
[   16.602209]  fput_close_sync+0x4c/0x138
[   16.602211]  __arm64_sys_close+0x44/0xa0
[   16.602215]  invoke_syscall+0xa8/0x138
[   16.602217]  el0_svc_common.constprop.0+0x114/0x140
[   16.602219]  do_el0_svc+0x28/0x58
[   16.602222]  el0_svc+0x48/0x310
[   16.602225]  el0t_64_sync_handler+0xc0/0x108

So the asymmetry is exactly what you describe: audio_enable/prepare check
hdmi->tmds_char_rate, audio_disable does not, and the read-modify-write in
clear_audio_infoframe hits the block with the PHY down.

Today I could reproduce it on demand, with the in-tree module of the same
kernel: disable one HDMI output in the compositor (KWin, so
atomic_disable() runs: tmds_char_rate = 0, PHY off), then

  aplay -D plughw:hdmi1,0 /usr/share/sounds/alsa/Front_Center.wav

open succeeds, prepare logs the usual "ASoC error (-19)", and the close
that follows dies in the same place, this time as a synchronous abort:

  Internal error: synchronous external abort: 0000000096000010 [#1] SMP
  pc : regmap_mmio_read32le+0x30/0xf0
  ...
  dw_hdmi_qp_bridge_clear_audio_infoframe+0x3c/0x78 [dw_hdmi_qp]
  drm_bridge_connector_clear_audio_infoframe+0x2c/0x68 [drm_display_helper]
  drm_atomic_helper_connector_hdmi_clear_audio_infoframe+0x70/0x110 [drm_display_helper]
  dw_hdmi_qp_audio_disable+0x28/0x108 [dw_hdmi_qp]
  hdmi_codec_shutdown+0x68/0xb0 [snd_soc_hdmi_codec]
  snd_soc_dai_shutdown+0x60/0xe0 [snd_soc_core]
  soc_pcm_close+0x40/0x80 [snd_soc_core]
  snd_pcm_release+0x68/0x110 [snd_pcm]
  __arm64_sys_close+0x44/0xa0
  note: aplay[52181] exited with irqs disabled
  note: aplay[52181] exited with preempt_count 1

(x19 = 0xffff800081ca0aa8, i.e. PKTSCHED_PKT_EN.) One more consequence of
the non-fatal variant that may be worth a line in the changelog: the task
dies while snd_pcm_release() is still holding the PCM's open_mutex, so
every later open() of that PCM blocks in D state until reboot - the card
is gone for the session. The reboot after that hung too (soft lockup in
rcu_exp_gp_kthread, a CPU never answering the NMI - I don't have a clean
causal chain for that second hang) and ended in a hard reset.

I read Cristian's comment on v4 - if you post a v5 that reuses
dw_hdmi_qp_bridge_clear_audio_infoframe() from the write path instead of
open-coding it, I am happy to run it on this board and reply with a
Tested-by. I have a serial console attached, so the negative case (PCM close
after the link failed to train) is something I can exercise here.

Thanks,
Igor