I2S Master Receive RX Driver Issues

Hi there,

I am working on an audio recording and transfer application using nRF5340 (microcontroller development kit) and SPH0465 (digital microphone with I2S support). I am using NCS and Zephyr 2.7.0. I have had success in implementing the I2S echo sample on my hardware. 

Configuration & Device Overlay:

1. SPH0645 is working in master mode. 

2. My configuration settings are:

# CONFIG_STDOUT_CONSOLE=y
CONFIG_PRINTK=y
CONFIG_PWM=y
CONFIG_LOG=y
CONFIG_LOG_PRINTK=y
CONFIG_LOG_MODE_IMMEDIATE=y
CONFIG_PWM_LOG_LEVEL_DBG=y

CONFIG_SERIAL=y
CONFIG_UART_INTERRUPT_DRIVEN=y
CONFIG_I2S=y
CONFIG_GPIO=y

3. and my device overlay is:

/*
 * Copyright (c) 2021 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: Apache-2.0
 */
 &clock {
	
	status = "okay";
};


&pinctrl {
	

	i2s0_default_alt: i2s0_default_alt {
		group1 {
			psels = <NRF_PSEL(I2S_SCK_M, 0, 26)>,
				<NRF_PSEL(I2S_LRCK_M, 0, 7)>,
				<NRF_PSEL(I2S_SDOUT, 1, 13)>,
				<NRF_PSEL(I2S_SDIN, 0, 25)>;
		};
	};
};


&clock {
	hfclkaudio-frequency = <11289600>;
};

i2s_rxtx: &i2s0 {
	status = "okay";
	pinctrl-0 = <&i2s0_default_alt>;
	pinctrl-names = "default";
	clock-source = "ACLK";
};

Application Code:

I have modified the echo sample for working only in reading mode, here is the application code:

/*
 * Copyright (c) 2021 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: Apache-2.0
 */

#include <zephyr/kernel.h>
#include <zephyr/sys/printk.h>
#include <zephyr/drivers/i2s.h>
// #include <zephyr/drivers/i2s_nrfx.h>
#include <zephyr/drivers/gpio.h>
#include <zephyr/sys/util.h>
#include <zephyr/sys/printk.h>
#include <inttypes.h>
#include <zephyr/logging/log.h>
#include <zephyr/logging/log_ctrl.h>
#include <string.h>
#include <zephyr/drivers/pwm.h>
#include <zephyr/drivers/uart.h>
// #include "i2s_registers.h"

// #define I2S_CONFIG_SWIDTH_SWIDTH_32Bit 1
LOG_MODULE_REGISTER(MODULE, 3);


///////////////////////////



#if DT_NODE_EXISTS(DT_NODELABEL(i2s_rxtx))
#define I2S_RX_NODE  DT_NODELABEL(i2s_rxtx)
#define I2S_TX_NODE  I2S_RX_NODE
#else
#define I2S_RX_NODE  DT_NODELABEL(i2s_rx)
#define I2S_TX_NODE  DT_NODELABEL(i2s_tx)
#endif
#define SAMPLE_FREQUENCY 16000//44100
#define SAMPLE_BIT_WIDTH  32
#define BYTES_PER_SAMPLE sizeof(int32_t)      
#define NUMBER_OF_CHANNELS 1


// size of a block for 100 ms of audio data
// #define BLOCK_SIZE 1024   // 4 samples of 4 bytes each
// for sample frequency of 16 kHz, 1 block will have 80 samples
// #define BLOCK_SIZE(_sample_rate, _number_of_channels) (BYTES_PER_SAMPLE * (_sample_rate / 200) * _number_of_channels)
#define SAMPLES_PER_BLOCK   ((SAMPLE_FREQUENCY / 10) * NUMBER_OF_CHANNELS)
#define BLOCK_SIZE  (BYTES_PER_SAMPLE * SAMPLES_PER_BLOCK)


#define INITIAL_BLOCKS 42 // for a total of 28 blocks
#define TIMEOUT 1000


/* Driver will allocate blocks from this slab to receive audio data into them.
 * Application, after getting a given block from the driver and processing its
 * data, needs to free that block.
 */
#define BLOCK_COUNT  (INITIAL_BLOCKS+2)    //20 

#define BYTES_PER_MEM_SLAB  BLOCK_SIZE*BLOCK_COUNT // 80 samples * 10 = 320 bytes * 10 = 3200 bytes
        
K_MEM_SLAB_DEFINE_STATIC(mem_slab, BLOCK_SIZE, BLOCK_COUNT, 4);

// static int16_t echo_block[SAMPLES_PER_BLOCK];
static volatile bool echo_enabled = true;
// static K_SEM_DEFINE(toggle_transfer, 1, 1);


// #if DT_NODE_HAS_STATUS(SW0_NODE, okay)
// static void sw0_handler(const struct device *dev, struct gpio_callback *cb,
// 			uint32_t pins)
// {
// 	bool enable = !echo_enabled;

// 	echo_enabled = enable;
// 	printk("Echo %sabled\n", (enable ? "en" : "dis"));
// }
// #endif

// #if DT_NODE_HAS_STATUS(SW1_NODE, okay)
// static void sw1_handler(const struct device *dev, struct gpio_callback *cb,
// 			uint32_t pins)
// {
// 	k_sem_give(&toggle_transfer);
// }
// #endif

// static bool init_buttons(void)
// {
// 	int ret;

// #if DT_NODE_HAS_STATUS(SW0_NODE, okay)
// 	static struct gpio_callback sw0_cb_data;

// 	if (!gpio_is_ready_dt(&sw0_spec)) {
// 		printk("%s is not ready\n", sw0_spec.port->name);
// 		return false;
// 	}

// 	ret = gpio_pin_configure_dt(&sw0_spec, GPIO_INPUT);
// 	if (ret < 0) {
// 		printk("Failed to configure %s pin %d: %d\n",
// 		       sw0_spec.port->name, sw0_spec.pin, ret);
// 		return false;
// 	}

// 	ret = gpio_pin_interrupt_configure_dt(&sw0_spec,
// 					      GPIO_INT_EDGE_TO_ACTIVE);
// 	if (ret < 0) {
// 		printk("Failed to configure interrupt on %s pin %d: %d\n",
// 		       sw0_spec.port->name, sw0_spec.pin, ret);
// 		return false;
// 	}

// 	gpio_init_callback(&sw0_cb_data, sw0_handler, BIT(sw0_spec.pin));
// 	gpio_add_callback(sw0_spec.port, &sw0_cb_data);
// 	printk("Press \"%s\" to toggle the echo effect\n", sw0_spec.port->name);
// #endif

// #if DT_NODE_HAS_STATUS(SW1_NODE, okay)
// 	static struct gpio_callback sw1_cb_data;

// 	if (!gpio_is_ready_dt(&sw1_spec)) {
// 		printk("%s is not ready\n", sw1_spec.port->name);
// 		return false;
// 	}

// 	ret = gpio_pin_configure_dt(&sw1_spec, GPIO_INPUT);
// 	if (ret < 0) {
// 		printk("Failed to configure %s pin %d: %d\n",
// 		       sw1_spec.port->name, sw1_spec.pin, ret);
// 		return false;
// 	}

// 	ret = gpio_pin_interrupt_configure_dt(&sw1_spec,
// 					      GPIO_INT_EDGE_TO_ACTIVE);
// 	if (ret < 0) {
// 		printk("Failed to configure interrupt on %s pin %d: %d\n",
// 		       sw1_spec.port->name, sw1_spec.pin, ret);
// 		return false;
// 	}

// 	gpio_init_callback(&sw1_cb_data, sw1_handler, BIT(sw1_spec.pin));
// 	gpio_add_callback(sw1_spec.port, &sw1_cb_data);
// 	printk("Press \"%s\" to stop/restart I2S streams\n", sw1_spec.port->name);
// #endif

// 	(void)ret;
// 	return true;
// }


// static void process_block_data(void *mem_block, uint32_t number_of_samples)
// {
// 	static bool clear_echo_block;

// 	if (echo_enabled) {
// 		for (int i = 0; i < number_of_samples; ++i) {
// 			int16_t *sample = &((int16_t *)mem_block)[i];
// 			*sample += echo_block[i];
// 			echo_block[i] = (*sample) / 2;
// 		}

// 		clear_echo_block = true;
// 	} else if (clear_echo_block) {
// 		clear_echo_block = false;
// 		memset(echo_block, 0, sizeof(echo_block));
// 	}
// }


// static bool prepare_transfer(const struct device *i2s_dev_rx,
// 			     const struct device *i2s_dev_tx)
// {
// 	int ret;

// 	for (int i = 0; i < INITIAL_BLOCKS; ++i) {
// 		void *mem_block;

// 		ret = k_mem_slab_alloc(&mem_slab, &mem_block, K_NO_WAIT);
// 		if (ret < 0) {
// 			printk("Failed to allocate TX block %d: %d\n", i, ret);
// 			return false;
// 		}

// 		memset(mem_block, 0, BLOCK_SIZE);

// 		// ret = i2s_write(i2s_dev_tx, mem_block, BLOCK_SIZE);
// 		// if (ret < 0) {
// 		// 	printk("Failed to write block %d: %d\n", i, ret);
// 		// 	return false;
// 		// }
// 	}

// 	return true;
// }


static bool trigger_command(const struct device *i2s_dev_rx,
			    const struct device *i2s_dev_tx,
			    enum i2s_trigger_cmd cmd)
{
	int ret;

	// if (i2s_dev_rx == i2s_dev_tx) {
	// 	ret = i2s_trigger(i2s_dev_rx, I2S_DIR_BOTH, cmd);
	// 	if (ret == 0) {
	// 		return true;
	// 	}
	// 	/* -ENOSYS means that commands for the RX and TX streams need
	// 	 * to be triggered separately.
	// 	 */
	// 	if (ret != -ENOSYS) {
	// 		printk("Failed to trigger command %d: %d\n", cmd, ret);
	// 		return false;
	// 	}
	// }

	ret = i2s_trigger(i2s_dev_rx, I2S_DIR_RX, cmd);
	if (ret < 0) {
		printk("Failed to trigger command %d on RX: %d\n", cmd, ret);
		return false;
	}

	// ret = i2s_trigger(i2s_dev_tx, I2S_DIR_TX, cmd);
	// if (ret < 0) {
	// 	printk("Failed to trigger command %d on TX: %d\n", cmd, ret);
	// 	return false;
	// }

	return true;
}

int main(void)
{
	
	const struct device *const i2s_dev_rx = DEVICE_DT_GET(I2S_RX_NODE);
	const struct device *const i2s_dev_tx = DEVICE_DT_GET(I2S_TX_NODE);
	struct i2s_config config;

	
	// if (!init_buttons()) {
	// 	return 0;
	// }

	
	if (!device_is_ready(i2s_dev_rx)) {
		printk("%s is not ready\n", i2s_dev_rx->name);
		return 0;
	}

	if (!device_is_ready(i2s_dev_rx)) {
		printk("%s is not ready\n", i2s_dev_rx->name);
		return 0;
	}

	config.word_size = SAMPLE_BIT_WIDTH;
	config.channels = NUMBER_OF_CHANNELS;
	config.format = I2S_FMT_DATA_FORMAT_I2S;
	config.options = I2S_OPT_BIT_CLK_MASTER | I2S_OPT_FRAME_CLK_MASTER;
	config.frame_clk_freq = SAMPLE_FREQUENCY;
	config.mem_slab = &mem_slab;
	config.block_size = BLOCK_SIZE;
	config.timeout = TIMEOUT;
	if (i2s_configure(i2s_dev_rx, I2S_DIR_RX, &config)!=0) {
		return 0;
	}
	
	printk("Streams started\n");

  while (1) {
    
	

		if (!trigger_command(i2s_dev_rx, i2s_dev_tx,
				     I2S_TRIGGER_START)) {
			return 0;
		}

		printk("Streams started\n");

		
			void *mem_block;
			uint32_t block_size;
			int ret;
			// while (k_mem_slab_alloc(&mem_slab, &mem_block, K_NO_WAIT)==0){
			
			ret = i2s_read(i2s_dev_rx, &mem_block, &block_size);
			if (ret < 0) {
				printk("Failed to read data: %d\n", ret);
				break;
			}

	}

    return 0;
} 

LOGS:

As shown in the application code, I have placed log commands at various locations. i2s driver file i2s_nrfx.c file also has logs of its own. And here is what I get:

*** Booting nRF Connect SDK v2.7.0-5cb85570ca43 ***<\r><\n>
*** Using Zephyr OS v3.6.99-100befc70c74 ***<\r><\n>
[00:00:00.261,260] <27>[0m<inf> i2s_nrfx: I2S MCK frequency: 1026327, actual PCM rate: 16036<27>[0m<\r><\n>
Streams started<\r><\n>
Stre[00:00:00.271,301] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x200435d0<27>[0m<\r><\n>
ams started<\r><\n>
[00:00:00.371,093] <27>[0m<inf> i2s_nrfx: Queued RX 0x20044ed0<27>[0m<\r><\n>
[00:00:00.376,647] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x20041cd0<27>[0m<\r><\n>
[00:00:00.382,781] <27>[0m<inf> i2s_nrfx: Released RX 0x20044ed0<27>[0m<\r><\n>
Failed to trigger command 0 on RX: -5<\r><\n>
[00:00:00.470,855] <27>[0m<inf> i2s_nrfx: Queued RX 0x200435d0<27>[0m<\r><\n>
[00:00:00.476,409] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x200403d0<27>[0m<\r><\n>
[00:00:00.570,617] <27>[0m<inf> i2s_nrfx: Queued RX 0x20041cd0<27>[0m<\r><\n>
[00:00:00.576,171] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x2003ead0<27>[0m<\r><\n>
[00:00:00.670,379] <27>[0m<inf> i2s_nrfx: Queued RX 0x200403d0<27>[0m<\r><\n>
[00:00:00.675,964] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x2003d1d0<27>[0m<\r><\n>
[00:00:00.770,172] <27>[0m<inf> i2s_nrfx: Queued RX 0x2003ead0<27>[0m<\r><\n>
[00:00:00.775,726] <27>[0m<inf> i2s_nrfx: Next buffers: 0/0x2003b8d0<27>[0m<\r><\n>
[00:00:00.869,934] <27>[1;31m<err> i2s_nrfx: No room in RX queue<27>[0m<\r><\n>
[00:00:00.875,671] <27>[0m<inf> i2s_nrfx: Freed RX 0x2003d1d0<27>[0m<\r><\n>
[00:00:00.881,195] <27>[1;31m<err> i2s_nrfx: No room in RX queue<27>[0m<\r><\n>
[00:00:00.886,993] <27>[0m<inf> i2s_nrfx: Freed RX 0x2003b8d0<27>[0m<\r><\n>

From the logs you can see see that I2S master is correctly set up for 1.026 MHz on SCK (BCLK) pin and 16.036 kHz on LRCK (WS). However, the incoming data from the microphone does not come in for too long before RX queue is full and the whole application is halted. 

No matter how much space I allocate in the BLOCK_SIZE in the application code, the RX queue in i2s_nrfx.c is filled after 5 buffers. And note from the logs that the application code has not even kicked in yet. 

Kindly advise how to allow i2s_nrfx.c to queue quite a few more buffers so that the application code can catch up and process data in time. 

Cheers.

Related