nRF Connect SDK Bug Report: Audio DMIC Race Condition

I have been working on an application for the nRF5340 using version 2.1.0 of the SDK, and it includes a task which collects audio data using the DMIC driver.  After adding Zigbee to the application, I began encountering errors with collecting audio data.  After a random amount of time (sometimes immediately, sometimes after several hours), calling dmic_read() would result in an error, with an accompanying "No audio data to be read" printout.  All subsequent calls to dmic_read() after stopping and restarting the audio data collection like normal would get the same error.  Attempting to reconfigure the microphone at any point after one of these errors would result in an error printout saying "Cannot configure device while it is active", despite having called dmic_trigger(..., DMIC_TRIGGER_STOP) before reconfiguring it.

It took me a while to wrap my head around the code in zephyr/drivers/audio/dmic_nrfx_pdm.c, but I believe I have found the source of this bug, and a simple fix for it.  I have been testing with the SDK v2.1.0, but the file in v2.2.0 is unchanged except for including one extra header file.  Here is the offending code, found at lines 461-466 (or 462-467 in v2.2.0).

	case DMIC_TRIGGER_STOP:
		if (drv_data->active) {
			nrfx_pdm_stop();
			drv_data->stopping = true;
		}
		break;

Before giving an in-depth explanation, this bug may be fixed by swapping lines 463 and 464, which I believe should not cause any unintended consequences:

	case DMIC_TRIGGER_STOP:
		if (drv_data->active) {
			drv_data->stopping = true;
			nrfx_pdm_stop();
		}
		break;

The function to stop the microphone stops the PDM driver, and sets a flag saying that the DMIC driver should be stopped and set to an inactive state.  The code which actually handles setting the device to be inactive is in the PDM event handler, which is called at some point after nrfx_pdm_stop() is called.  In most cases, the next line of code will execute before the event handler, and things will work as expected.  However, bad scheduling can result in the event handler being called before the "stopping" flag is set to true, meaning that the PDM driver will be de-initialized but the DMIC device will remain in an active state.

This prevents any calls to dmic_trigger(..., DMIC_TRIGGER_START) from doing anything, as the device is apparently already active.  Attempting to read data from the DMIC device will not find any audio data, resulting in the error I was seeing.  Calling dmic_trigger(..., DMIC_TRIGGER_STOP) will make another call to nrfx_pdm_stop(), but because the PDM driver has already been stopped, there are no further calls to the event handler, and hence the device never gets set to an inactive state.

This bug is easy to duplicate by putting a LOG_ERR() printout (or some other function which will waste time) between lines 463 and 464 and calling a routine which starts and stops the microphone repeatedly.  I do not have code written for this, but it should be simple to modify the code found at zephyr/samples/drivers/audio/dmic/src/main.c to call do_pdm_transfer() repeatedly from within a task.

Hopefully this is enough to reproduce the error and make a fix for the SDK.  I think the section of code I identified is the sole source of it, but it's possible that there are other issues I missed.  For the moment, I will keep developing with my modified version of the v2.1.0 SDK.

Related