Skip to content

Conversation

@mariopaja
Copy link
Contributor

While #94696 successfully addressed STOP/START, it failed to fix mem_buffer release.

This PR addresses the mem_buffer release during TX callback.

For debugging purposes add the following:

i2s_stm32_sai.c

LOG_ERR("Freeing memory slab %p", mem_block_tmp);
k_mem_slab_free(stream->i2s_cfg.mem_slab, mem_block_tmp);
LOG_WRN("k_mem_slab_num_free_get(): %d",k_mem_slab_num_free_get(stream->i2s_cfg.mem_slab));

prj.conf

CONFIG_LOG=y
CONFIG_I2S_LOG_LEVEL_DBG=y
CONFIG_LOG_MODE_IMMEDIATE=y
CONFIG_I2S_STM32_SAI_BLOCK_COUNT=20

DRAIN

  1. First buffer not released:
  2. Last Buffer released two times

LOG Before:

[00:00:00.037,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_configure: SAI_STEREOMODE
[00:00:00.045,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_START
[00:00:00.053,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_DRAIN
[00:00:00.061,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000380
[00:00:00.068,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 1
[00:00:00.075,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000480
[00:00:00.082,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 2
[00:00:00.089,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000580
[00:00:00.096,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 3
[00:00:00.103,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000680
[00:00:00.110,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 4
[00:00:00.118,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000780
[00:00:00.125,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 5
[00:00:00.132,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000880
[00:00:00.139,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 6
[00:00:00.146,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000980
[00:00:00.153,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 7
[00:00:00.160,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000a80
[00:00:00.167,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 8
[00:00:00.174,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000b80
[00:00:00.182,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 9
[00:00:00.189,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000c80
[00:00:00.196,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 10
[00:00:00.203,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000d80
[00:00:00.210,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 11
[00:00:00.217,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000e80
[00:00:00.225,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 12
[00:00:00.232,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000f80
[00:00:00.239,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 13
[00:00:00.246,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001080
[00:00:00.253,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 14
[00:00:00.260,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001180
[00:00:00.268,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 15
[00:00:00.275,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001280
[00:00:00.282,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 16
[00:00:00.289,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001380
[00:00:00.296,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 17
[00:00:00.303,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001480
[00:00:00.311,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 18
[00:00:00.318,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:00.325,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 19
[00:00:00.332,000] <dbg> i2s_stm32_sai: HAL_SAI_TxCpltCallback: Exit TX callback, no more data in the queue
[00:00:00.342,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:00.349,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 20

LOG After:

[00:00:00.037,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_configure: SAI_STEREOMODE
[00:00:00.045,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_START
[00:00:00.053,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_DRAIN
[00:00:00.061,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000280
[00:00:00.068,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 1
[00:00:00.075,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000380
[00:00:00.082,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 2
[00:00:00.089,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000480
[00:00:00.096,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 3
[00:00:00.103,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000580
[00:00:00.110,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 4
[00:00:00.118,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000680
[00:00:00.125,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 5
[00:00:00.132,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000780
[00:00:00.139,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 6
[00:00:00.146,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000880
[00:00:00.153,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 7
[00:00:00.160,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000980
[00:00:00.167,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 8
[00:00:00.174,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000a80
[00:00:00.182,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 9
[00:00:00.189,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000b80
[00:00:00.196,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 10
[00:00:00.203,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000c80
[00:00:00.210,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 11
[00:00:00.217,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000d80
[00:00:00.225,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 12
[00:00:00.232,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000e80
[00:00:00.239,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 13
[00:00:00.246,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000f80
[00:00:00.253,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 14
[00:00:00.260,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001080
[00:00:00.268,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 15
[00:00:00.275,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001180
[00:00:00.282,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 16
[00:00:00.289,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001280
[00:00:00.296,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 17
[00:00:00.303,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001380
[00:00:00.311,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 18
[00:00:00.318,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001480
[00:00:00.325,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 19
[00:00:00.332,000] <dbg> i2s_stm32_sai: HAL_SAI_TxCpltCallback: Exit TX callback, no more data in the queue
[00:00:00.342,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:00.349,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 20

STOP

Add into samples/drivers/i2s/output

  ret = i2s_trigger(dev_i2s, I2S_DIR_TX, I2S_TRIGGER_STOP);
  if (ret < 0) {
      printf("Could not trigger I2S tx\n");
      return ret;
  }
  k_msleep(1000);

  ret = i2s_trigger(dev_i2s, I2S_DIR_TX, I2S_TRIGGER_START);
  if (ret < 0) {
      printf("Could not trigger I2S tx\n");
      return ret;
  }

LOG Before:

  1. Second buffer is not released
  2. Last buffer is released two times
[00:00:00.068,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000280
[00:00:00.075,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 1
[00:00:01.082,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_START
[00:00:01.091,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000480
[00:00:01.098,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 2
[00:00:01.105,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000580
[00:00:01.113,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 3
[00:00:01.120,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000680
[00:00:01.127,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 4
[00:00:01.134,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000780
[00:00:01.141,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 5
[00:00:01.148,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000880
[00:00:01.155,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 6
[00:00:01.162,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000980
[00:00:01.170,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 7
[00:00:01.177,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000a80
[00:00:01.184,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 8
[00:00:01.191,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000b80
[00:00:01.198,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 9
[00:00:01.205,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000c80
[00:00:01.212,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 10
[00:00:01.220,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000d80
[00:00:01.227,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 11
[00:00:01.234,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000e80
[00:00:01.241,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 12
[00:00:01.248,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000f80
[00:00:01.255,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 13
[00:00:01.262,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001080
[00:00:01.270,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 14
[00:00:01.277,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001180
[00:00:01.284,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 15
[00:00:01.291,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001280
[00:00:01.298,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 16
[00:00:01.305,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001380
[00:00:01.313,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 17
[00:00:01.320,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001480
[00:00:01.327,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 18
[00:00:01.334,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:01.341,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 19
[00:00:01.348,000] <dbg> i2s_stm32_sai: HAL_SAI_TxCpltCallback: Exit TX callback, no more data in the queue
[00:00:01.359,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:01.366,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 20

LOG After:

[00:00:00.068,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000280
[00:00:00.075,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 1
[00:00:01.082,000] <dbg> i2s_stm32_sai: i2s_stm32_sai_trigger: I2S_TRIGGER_START
[00:00:01.091,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000380
[00:00:01.098,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 2
[00:00:01.105,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000480
[00:00:01.113,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 3
[00:00:01.120,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000580
[00:00:01.127,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 4
[00:00:01.134,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000680
[00:00:01.141,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 5
[00:00:01.148,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000780
[00:00:01.155,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 6
[00:00:01.162,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000880
[00:00:01.170,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 7
[00:00:01.177,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000980
[00:00:01.184,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 8
[00:00:01.191,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000a80
[00:00:01.198,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 9
[00:00:01.205,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000b80
[00:00:01.212,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 10
[00:00:01.220,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000c80
[00:00:01.227,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 11
[00:00:01.234,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000d80
[00:00:01.241,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 12
[00:00:01.248,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000e80
[00:00:01.255,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 13
[00:00:01.262,000] <err> i2s_stm32_sai: Freeing memory slab 0x20000f80
[00:00:01.270,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 14
[00:00:01.277,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001080
[00:00:01.284,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 15
[00:00:01.291,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001180
[00:00:01.298,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 16
[00:00:01.305,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001280
[00:00:01.313,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 17
[00:00:01.320,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001380
[00:00:01.327,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 18
[00:00:01.334,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001480
[00:00:01.341,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 19
[00:00:01.348,000] <dbg> i2s_stm32_sai: HAL_SAI_TxCpltCallback: Exit TX callback, no more data in the queue
[00:00:01.359,000] <err> i2s_stm32_sai: Freeing memory slab 0x20001580
[00:00:01.366,000] <wrn> i2s_stm32_sai: k_mem_slab_num_free_get(): 20

This change fixes a wrong buffer release on tx callback which
was not correctly fixed by
zephyrproject-rtos#94696.

Signed-off-by: Mario Paja <mariopaja@hotmail.com>
Set mem_block to NULL after the STOPPING command in order to exit
TX callback at the end of the buffer transmission.

Signed-off-by: Mario Paja <mariopaja@hotmail.com>
@sonarqubecloud
Copy link

Copy link
Contributor

@evgeniy-paltsev evgeniy-paltsev left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wanted to create issue about this, but there is already a fix :)

Copy link
Contributor

@etienne-lms etienne-lms left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me, as far as I can tell.

@erwango
Copy link
Member

erwango commented Sep 2, 2025

@puliceworx can you have a test ?

@mariopaja
Copy link
Contributor Author

mariopaja commented Sep 2, 2025

@schweigstill could you also test it?

@evgeniy-paltsev did you have time to test these changes, since you had also noticed this issue?

@etienne-lms
Copy link
Contributor

Can't tests/drivers/i2s materials be used on a loopback mode?

@mariopaja
Copy link
Contributor Author

Can't tests/drivers/i2s materials be used on a loopback mode?

I think loopback mode does not check the memory buffer if is released or not :/

@puliceworx
Copy link

@erwango @mariopaja

Tested a few times. I get the correct (same) log output as in the PR.

@schweigstill
Copy link
Contributor

@schweigstill could you also test it?
@mariopaja Yes, it works as intended. Sorry, I was very busy the last few days...

@evgeniy-paltsev
Copy link
Contributor

@evgeniy-paltsev did you have time to test these changes, since you had also noticed this issue?

Yep, I've tested it (even before approving :)

@kartben kartben merged commit a5107fb into zephyrproject-rtos:main Sep 2, 2025
30 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

8 participants