Re: [PATCH v2 3/6] ASoC: renesas: fsi: Fix trigger stop ordering

[Bui Duc Phuc]

Hi Morimoto-san,

Even after reordering the sequence as follows:
    fsi_stream_stop(fsi, io);
    if (!ret)
        ret = fsi_hw_shutdown(fsi, dai->dev);
I had previously tested this change and did not observe any issues.
However, in more recent testing under different conditions, I noticed
a system hang.
It seems that the interrupt handler may still be invoked after
interrupts are disabled and the SPU clock is turned off.
The following log was observed:

root@localhost:~#
root@localhost:~# aplay /audio/file_example_WAV_2MG.wav
[   51.580000] >>>>>DEBUG: enter fsi_dai_startup
Playing WAVE '/audio/file_example_WAV_2MG.wav' : Signed 16 bit Little
Endian, Rat[   51.590000] wm8978 1-001a
: Imprecise sampling rate: 48000Hz, consider using PLL
e 44100 Hz, Stereo
[   51.640000] >>>>>DEBUG: enter fsi_hw_startup
[   51.640000] >>>>>DEBUG: enter fsi_pio_start_stop, enable : 1
[   62.610000] >>>>>DEBUG: enter fsi_pio_start_stop, enable : 0
[   62.610000] >>>>>DEBUG: enter fsi_hw_shutdown
[   62.610000] FSI BUG: READ after clock OFF
[   62.610000] CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Not tainted
7.0.0-09892-g26b66fbaf162-dirty #5 VOLUNTARY
[   62.610000] Hardware name: Generic R8A7740 (Flattened Device Tree)
[   62.610000] Call trace:
[   62.610000]  unwind_backtrace from show_stack+0x10/0x14
[   62.610000]  show_stack from dump_stack_lvl+0x50/0x64
[   62.610000]  dump_stack_lvl from __fsi_reg_read+0x30/0x5c
[   62.610000]  __fsi_reg_read from fsi_count_fifo_err+0x14/0x88
[   62.610000]  fsi_count_fifo_err from fsi_interrupt+0xa0/0xc0
[   62.610000]  fsi_interrupt from __handle_irq_event_percpu+0x1a8/0x1ec
[   62.610000]  __handle_irq_event_percpu from handle_irq_event_percpu+0xc/0x38
[   62.610000]  handle_irq_event_percpu from handle_irq_event+0x44/0x68
[   62.610000]  handle_irq_event from handle_fasteoi_irq+0xa8/0x130
[   62.610000]  handle_fasteoi_irq from handle_irq_desc+0x64/0x7c
[   62.610000]  handle_irq_desc from gic_handle_irq+0x60/0x70
[   62.610000]  gic_handle_irq from generic_handle_arch_irq+0x28/0x3c
[   62.610000]  generic_handle_arch_irq from __irq_svc+0x88/0xb0
[   62.610000] Exception stack(0xc0d01f48 to 0xc0d01f90)
[   62.610000] 1f40:                   00000003 00000001 000176c4
40000000 00000000 00000000
[   62.610000] 1f60: c0d03f98 c0d07880 c0d90b82 c0d03fd4 c0aea642
00000000 99cea980 c0d01f98
[   62.610000] 1f80: c08228f4 c0822c68 600f0013 ffffffff
[   62.610000]  __irq_svc from default_idle_call+0x24/0x30
[   62.610000]  default_idle_call from do_idle+0xcc/0x124
[   62.610000]  do_idle from cpu_startup_entry+0x28/0x2c
[   62.610000]  cpu_startup_entry from rest_init+0x94/0xb0
[   62.610000]  rest_init from start_kernel+0x608/0x6bc
[   62.610000] FSI BUG: READ after clock OFF
[   62.610000] CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Not tainted
7.0.0-09892-g26b66fbaf162-dirty #5 VOLUNTARY
[   62.610000] Hardware name: Generic R8A7740 (Flattened Device Tree)
[   62.610000] Call trace:
[   62.610000]  unwind_backtrace from show_stack+0x10/0x14
[   62.610000]  show_stack from dump_stack_lvl+0x50/0x64
[   62.610000]  dump_stack_lvl from __fsi_reg_read+0x30/0x5c
[   62.610000]  __fsi_reg_read from fsi_count_fifo_err+0x24/0x88
[   62.610000]  fsi_count_fifo_err from fsi_interrupt+0xa0/0xc0
[   62.610000]  fsi_interrupt from __handle_irq_event_percpu+0x1a8/0x1ec
[   62.610000]  __handle_irq_event_percpu from handle_irq_event_percpu+0xc/0x38
[   62.610000]  handle_irq_event_percpu from handle_irq_event+0x44/0x68
[   62.610000]  handle_irq_event from handle_fasteoi_irq+0xa8/0x130
[   62.610000]  handle_fasteoi_irq from handle_irq_desc+0x64/0x7c
[   62.610000]  handle_irq_desc from gic_handle_irq+0x60/0x70
[   62.610000]  gic_handle_irq from generic_handle_arch_irq+0x28/0x3c
[   62.610000]  generic_handle_arch_irq from __irq_svc+0x88/0xb0
[   62.610000] Exception stack(0xc0d01f48 to 0xc0d01f90)
[   62.610000] 1f40:                   00000003 00000001 000176c4
40000000 00000000 00000000
[   62.610000] 1f60: c0d03f98 c0d07880 c0d90b82 c0d03fd4 c0aea642
00000000 99cea980 c0d01f98
[   62.610000] 1f80: c08228f4 c0822c68 600f0013 ffffffff
[   62.610000]  __irq_svc from default_idle_call+0x24/0x30
[   62.610000]  default_idle_call from do_idle+0xcc/0x124
[   62.610000]  do_idle from cpu_startup_entry+0x28/0x2c
[   62.610000]  cpu_startup_entry from rest_init+0x94/0xb0
[   62.610000]  rest_init from start_kernel+0x608/0x6bc


.......

In fsi_pio_start_stop(), I also tried adding the following:

    if (enable)
        fsi_irq_enable(fsi, io);
    else {
        fsi_irq_disable(fsi, io);
+    disable_irq_nosync(master->irq);
+        fsi_irq_clear_status(fsi);
     }

However, this still does not resolve the issue where the interrupt
handler may still be invoked after the SPU clock has been turned off.

Do you have any suggestions on this issue?
If we still want to keep the SPU clock enable/disable inside
hw_start/hw_shutdown,
we need to properly handle this race condition where the interrupt
handler is still being triggered after hw_shutdown.

Otherwise, moving the SPU clock control into dai_start/dai_shutdown
seems to be a safer approach,
since at that point all interrupts have already been fully processed.

Best regards,
Phuc