Skip to content

[BUG IMX] Input/output error when mixing two streams #3802

Closed
#3803
Closed
[BUG IMX] Input/output error when mixing two streams#3802
#3803
Assignees
iuliana-prodan
Labels
IMXApplies to i.MX platformbugSomething isn't working as expected

Description

@iuliana-prodan
iuliana-prodan
opened on Feb 1, 2021

Describe the bug
Input/output error when when mixing two streams.

To Reproduce
$aplay -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom & aplay -Dhw:1,1 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom &

Reproduction Rate
100%

Environment

  1. Branch name and commit hash of the 2 repositories: sof (firmware/topology) and linux (kernel driver).
    • Kernel: 5.10
    • SOF: master
  2. Name of the topology file
    • Topology: sof-imx8-wm8960-mixer.tplg, sof-imx8-cs42888-mixer.tplg, sof-imx8mp-wm8960-mixer.tplg
  3. Name of the platform(s) on which the bug is observed.
    • Platform: i.MX8QXP/i.MX8QM/i.MX8MP

Screenshots or console output

root@imx8qxpc0mek:~# aplay -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom & aplay -Dhw:1,1 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom &
[1] 560
[2] 561
root@imx8qxpc0mek:~# Playing raw data '/dev/urandom' : Playing raw data '/dev/urandom' : Signed 16 bit Little Endian, Signed 16 bit Little Endian, Rate 48000 Hz, Rate 48000 Hz, StereoStereo


root@imx8qxpc0mek:~# aplay: pcm_write:2061: aplay: pcm_write:2061: write error: Input/output errorwrite error: Input/output error


[1]-  Done(1)                 aplay -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom
[2]+  Done(1)                 aplay -Dhw:1,1 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom
root@imx8qxpc0mek:~#
root@imx8qxpc0mek:~# ./sof-logger -t -l /lib/firmware/imx/sof/sof-imx8x.ldc 
         TIMESTAMP              DELTA C# COMPONENT          LOCATION                      CONTENT
[81523859753.437500] (             nan) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81523860036.666672] (      283.229156) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81523892089.583344] (    32052.916016) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81523892409.270844] (      319.687500) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81523892734.635422] (      325.364594) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81523893066.562500] (      331.927094) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81523893349.479172] (      282.916656) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81523925364.114594] (    32014.634766) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81523925676.041672] (      311.927094) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81523926021.927094] (      345.885406) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81523926353.229172] (      331.302094) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81523926644.479172] (      291.250000) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81523958758.072922] (    32113.593750) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81523959075.312500] (      317.239594) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81523959400.260422] (      324.947906) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81523959731.562500] (      331.302094) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81523960014.166672] (      282.604156) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81523992138.333344] (    32124.166016) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81523992456.979172] (      318.645844) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81523992788.906250] (      331.927094) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81523993112.395844] (      323.489594) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81523993395.312500] (      282.916656) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81524025452.447922] (    32057.134766) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81524025764.062500] (      311.614594) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81524026087.135422] (      323.072906) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81524026410.312500] (      323.177094) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0 < period bytes 192, possible glitch
[81524026693.854172] (      283.541656) c0 dai          1.2            src/audio/dai.c:855  WARN dai_copy(): nothing to copy
[81524058770.000000] (    32076.146484) c0 buffer       3.15        src/audio/buffer.c:271  comp_update_buffer_consume(), no bytes to consume, source->comp.id = 13, source->comp.type = 5, sink->comp.id = 0, sink->comp.type = 6
[81524059089.895844] (      319.895844) c0 buffer       1.4         src/audio/buffer.c:231  comp_update_buffer_produce(), no bytes to produce, source->comp.id = 0, source->comp.type = 6, sink->comp.id = 1, sink->comp.type = 5
[81524059414.843750] (      324.947906) c0 pga          1.1   ../audio/volume/volume.c:729  volume_copy(), source_bytes = 0x0, sink_bytes = 0x0
[81524059736.458344] (      321.614594) c0 dai          1.2            src/audio/dai.c:847  WARN dai_copy(): Copy_bytes 0 + avail bytes 0

Activity

  1. iuliana-prodan
    added
    bugSomething isn't working as expected
    on Feb 1, 2021
  2. iuliana-prodan
    self-assigned this
    on Feb 1, 2021

  3. giuzan commented on Feb 2, 2021

    @giuzan
    giuzan
    on Feb 2, 2021

    Hi @iuliana-prodan,

    I experienced the issue on iMX8QM using sof-imx8-cs42888-mixer.tplg. The issue can be reproduced in both branches imx-stable-v1.5 and imx-stable-v1.6.

    I applied the commits of this PR #3803 on the top of both branches and I performed some tests.

    Test 1

    It is basically the test you reported in bug description.

    I run the following command:

    aplay -D hw:1,0 test_1.wav & aplay -D hw:1,1 test_2.wav

    The issue seems to be fixed (in both branches), I did not experience it anymore. Before the fix, I used to reproduce the issue simply playing on a single pipeline only. Through this test, I also tried to really mix the two streams.

    Test 2

    I tested a new scenario. I run the following command:

    aplay -D hw:1,0 test_1.wav & aplay -D hw:1,1 test_2.wav & arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10

    In this way also the capture pipeline is involved.
    I saw input/output errors (in both branches), could be the problem related to #3690?
    Moreover, rarely happens that a "strange noise" is heard and no input/errors happen.

    I hope that these information helps you.

    I attach the script I'm using to perform the tests:

    #!/bin/bash

p1=1
p2=1
r1=1

logs_recorder()
{
    sof-logger -l /lib/firmware/imx/sof/sof-imx8.ldc -t >> report.txt
}

test_aplay_1()
{
    while true
    do
        echo "start | ${p1} | aplay -D hw:1,0 test_1.wav" >> report.txt
        echo "start | ${p1} | aplay -D hw:1,0 test_1.wav"
        aplay -D hw:1,0 test_1.wav
        echo "end | ${p1} | aplay -D hw:1,0 test_1.wav" >> report.txt
        echo "end | ${p1} | aplay -D hw:1,0 test_1.wav"
        p1=$((p1+1))
    done
}

test_aplay_2()
{
    while true
    do
        echo "start | ${p2} | aplay -D hw:1,1 test_2.wav" >> report.txt
        echo "start | ${p2} | aplay -D hw:1,1 test_2.wav"
        aplay -D hw:1,1 test_2.wav
        echo "end | ${p2} | aplay -D hw:1,1 test_2.wav" >> report.txt
        echo "end | ${p2} | aplay -D hw:1,1 test_2.wav"
        p2=$((p2+1))
    done
}

test_arecord()
{
    while true
    do
        echo "start | ${r1} | arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10" >> report.txt
        echo "start | ${r1} | arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10"
        arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10
        echo "end | ${r1} | arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10" >> report.txt
        echo "end | ${r1} | arecord -D hw:1,0 -c 2 -r 48000 -f S16_LE record.wav -d 10"
        r1=$((r1+1))
    done
}

echo '* * *' > report.txt

logs_recorder &
test_aplay_1 &
test_aplay_2 &
test_arecord

  4. iuliana-prodan commented on Feb 2, 2021

    @iuliana-prodan
    iuliana-prodan
    on Feb 2, 2021
    ContributorAuthor

    @giuzan Thanks for testing this!
    Your Test 2 scenario it's a problem we've also discovered and, since you mentioned it, I've created another bug: #3809.
    This is not quite related with the mixer issue: the playback and record are started/stopped multiple times and, at some point, it fails with Input/output error.

    I'm looking into this, now.

  5. iuliana-prodan commented on Feb 2, 2021

    @iuliana-prodan
    iuliana-prodan
    on Feb 2, 2021
    ContributorAuthor

    @giuzan For Test 2 scenario, if you don't start/stop the playback and record it works ok:

    root@imx8qxpc0mek:~# date
Tue Feb  2 16:58:03 UTC 2021
root@imx8qxpc0mek:~# aplay -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom & aplay -Dhw:1,1 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom & arecord  -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/null &
[1] 626
[2] 627
[3] 628
root@imx8qxpc0mek:~# Recording raw data '/dev/null' : Playing raw data '/dev/urandom' : Playing raw data '/dev/urandom' : Signed 16 bit Little Endian, Signed 16 bit Little Endian, Signed 16 bit Little Endian, Rate 48000 Hz, Rate 48000 Hz, Rate 48000 Hz, StereoStereoStereo

root@imx8qxpc0mek:~# jobs
[1]   Running                 aplay -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom &
[2]-  Running                 aplay -Dhw:1,1 -f S16_LE -c 2 -r 48000 -t raw /dev/urandom &
[3]+  Running                 arecord -Dhw:1,0 -f S16_LE -c 2 -r 48000 -t raw /dev/null &
root@imx8qxpc0mek:~# 
root@imx8qxpc0mek:~# date
Tue Feb  2 17:26:31 UTC 2021
root@imx8qxpc0mek:~#

    The start/stop playback & record will be handled in #3809.

  6. paulstelian97
    added
    IMXApplies to i.MX platform
    on Feb 3, 2021
  7. iuliana-prodan
    added 2 commits that reference this issue on Feb 4, 2021

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    61ad267

    platform: imx: use DMA_DOMAIN in full synchronous mode

    72c1896

  8. lgirdwood commented on Feb 5, 2021

    @lgirdwood
    lgirdwood
    on Feb 5, 2021
    Member

    @iuliana-prodan fwiw, should be another two weeks until v1.7 final, so plenty of time to get the fixes merged for imx.

  9. dbaluta
    closed this as completedin #3803on Feb 9, 2021
  10. dbaluta
    added 2 commits that reference this issue on Feb 9, 2021

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    b732c4f

    platform: imx: use DMA_DOMAIN in full synchronous mode

    789a286
  11. iuliana-prodan
    added 4 commits that reference this issue on Feb 10, 2021

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    d9800f0

    platform: imx: use DMA_DOMAIN in full synchronous mode

    28d867b

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    abb8c80

    platform: imx: use DMA_DOMAIN in full synchronous mode

    8963436
  12. keyonjie
    added 2 commits that reference this issue on Mar 10, 2021

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    961f725

    platform: imx: use DMA_DOMAIN in full synchronous mode

    f155cf1
  13. lgirdwood
    added 2 commits that reference this issue on Mar 18, 2021

    schedule: dma_multi_chan: do not skip tasks for dma_domain scheduler

    6fa9706

    platform: imx: use DMA_DOMAIN in full synchronous mode

    63faeea
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

IMXApplies to i.MX platformbugSomething isn't working as expected

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions