NXP I2S using DMA never completes

[JoeyFreeland-DojoFive]

Describe the bug
I am trying to get the i2s output example working on a board I created, based off of the frdm_rw612 board. During execution I see that the request is going out on DMA1. It never completes and the program hangs. I set breakpoints in the I2S driver (i2s_mcux_flexcomm.c) and also the DMA driver (dma_mcux_lpc) and I never see any DMA callbacks being called. I am thinking there could a secure/non-secure mode issue here? Not sure.

To Reproduce
Build and run the samples/i2s/output example for frdm_rw612, with an I2S interface on flexcomm0 (I also tested flexcomm1 and got the same results.

Expected Behavior
No I2S output appears on the output pins, and observe the serial log and see that <err> i2s_mcux_flexcomm: k_msgq_put failed -11 is printed, indicating that no I2S data is being written and the queue is full.

Impact
I2S driver fails to operate.

Logs and console output

[00:01:09.381,875] <dbg> dma_mcux_lpc: dma_mcux_lpc_configure: channel is 1
[00:01:09.391,459] <dbg> dma_mcux_lpc: dma_mcux_lpc_configure: INSTALL call back on channel 1
[00:01:09.402,580] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: dma_slot is 0
[00:01:09.413,050] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: channel_direction is 1
[00:01:09.424,312] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: complete_callback_en is 0
[00:01:09.435,839] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: error_callback_dis is 0
[00:01:09.447,189] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: source_handshake is 0
[00:01:09.458,367] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: dest_handshake is 0
[00:01:09.469,363] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: channel_priority is 0
[00:01:09.480,540] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: source_chaining_en is 0
[00:01:09.491,892] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: dest_chaining_en is 0
[00:01:09.503,069] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: linked_channel is 0
[00:01:09.514,069] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: source_data_size is 4
[00:01:09.525,245] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: dest_data_size is 4
[00:01:09.536,245] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: source_burst_length is 0
[00:01:09.547,683] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: dest_burst_length is 0
[00:01:09.558,946] <dbg> i2s_mcux_flexcomm: i2s_mcux_config_dma_blocks: block_count is 1
[00:01:09.569,694] <dbg> dma_mcux_lpc: dma_mcux_lpc_start: START TRANSFER
[00:01:09.579,100] <dbg> dma_mcux_lpc: dma_mcux_lpc_start: DMA CTRL 0x1
[00:01:11.588,406] <err> i2s_mcux_flexcomm: k_msgq_put failed -11

If able to view specific registers, you can verify that the proper channel is active, but not busy. And no interrupts pending.

Environment
Zephyr v4.1.0, built on macOS

[github-actions]

Hi @JoeyFreeland-DojoFive! We appreciate you submitting your first issue for our open-source project. 🌟

Even though I'm a bot, I can assure you that the whole community is genuinely grateful for your time and effort. 🤖💙

[henrikbrixandersen]

Please use our bug template when reporting bugs. You need to edit this issue to include the information requested in https://github.com/zephyrproject-rtos/zephyr/blob/main/.github/ISSUE_TEMPLATE/001_bug_report.md

[JoeyFreeland-DojoFive]

Update on this issue: It does work on flexcomm14, but not on flexcomm0 or flexcomm1. I've tracked it down to the clocks not being configured on flexcomm0 (FC0FCLKSEL is set to 7). Still trying to figure out why it only works on 14.

Another update: After erasing flash and reflashing both MCU boot and the application, it looks like flexcomm14 was being set up by a fluke somehow, by MCUboot. Nothing in zephyr application land was initializing it. Now, it is not initialized at all.

[JoeyFreeland-DojoFive]

@dleach02 @mmahadevan108 I made a change to zephyr/soc/nxp/rw/soc.c yesterday, in the function clock_init(). Right after the I2C clock init section (starts with comment /* Any flexcomm can be I2C */) I added this:

/* Any flexcomm can be I2S */
#if (DT_NODE_HAS_COMPAT_STATUS(DT_NODELABEL(flexcomm0), nxp_lpc_i2s, okay)) && CONFIG_I2S
	CLOCK_SetFRGClock(&(const clock_frg_clk_config_t){0, kCLOCK_FrgPllDiv, 255, 0});
	CLOCK_AttachClk(kFRG_to_FLEXCOMM0);
#endif
#if (DT_NODE_HAS_COMPAT_STATUS(DT_NODELABEL(flexcomm1), nxp_lpc_i2s, okay)) && CONFIG_I2S
	CLOCK_SetFRGClock(&(const clock_frg_clk_config_t){1, kCLOCK_FrgPllDiv, 255, 0});
	CLOCK_AttachClk(kFRG_to_FLEXCOMM1);
#endif
#if (DT_NODE_HAS_COMPAT_STATUS(DT_NODELABEL(flexcomm2), nxp_lpc_i2s, okay)) && CONFIG_I2S
	CLOCK_SetFRGClock(&(const clock_frg_clk_config_t){2, kCLOCK_FrgPllDiv, 255, 0});
	CLOCK_AttachClk(kFRG_to_FLEXCOMM2);
#endif
#if (DT_NODE_HAS_COMPAT_STATUS(DT_NODELABEL(flexcomm3), nxp_lpc_i2s, okay)) && CONFIG_I2S
	CLOCK_SetFRGClock(&(const clock_frg_clk_config_t){3, kCLOCK_FrgPllDiv, 255, 0});
	CLOCK_AttachClk(kFRG_to_FLEXCOMM3);
#endif
#if (DT_NODE_HAS_COMPAT_STATUS(DT_NODELABEL(flexcomm14), nxp_lpc_i2s, okay)) && CONFIG_I2S
	CLOCK_SetFRGClock(&(const clock_frg_clk_config_t){14, kCLOCK_FrgPllDiv, 255, 0});
	CLOCK_AttachClk(kFRG_to_FLEXCOMM14);
#endif

After doing this, flexcomm0 was able to output the I2S data. Is it possible that I2S clock init was missed in the original soc.c implementation?