Skip to content

up2: pulseaudio playback fails after suspend/resume #764

Closed

Description

@kv2019i

PCM playback to headset fails to recover after suspend/resume on UP2 board.

Commands:
sh1> /usr/bin/pulseaudio -vv
sh2> aplay -D default test.wav
sh3> sudo rtcwake -m mem -s 2

Notes:

  • without pulseaudio, recovery from suspend/resume works
  • @plbossart it seems at least the rewinds fails, this is probably what you referred to in a mail recently

Log:
I: [pulseaudio] protocol-native.c: Final latency 624.99 ms = 250.02 ms + 2124.99 ms + 124.99 ms
D: [alsa-sink-Port5 (
)] alsa-sink.c: Latency set to 124.99ms
D: [alsa-sink-Port5 ()] alsa-sink.c: hwbuf_unused=41284
D: [alsa-sink-Port5 (
)] alsa-sink.c: setting avail_min=15439
D: [alsa-sink-Port5 ()] alsa-sink.c: Requesting rewind due to latency change.
D: [alsa-sink-Port5 (
)] alsa-sink.c: Requested to rewind 65280 bytes.
D: [alsa-sink-Port5 ()] alsa-sink.c: Limited to 44864 bytes.
D: [alsa-sink-Port5 (
)] alsa-sink.c: before: 11216
D: [alsa-sink-Port5 ()] alsa-sink.c: after: 11216
D: [alsa-sink-Port5 (
)] alsa-sink.c: Rewound 44864 bytes.
D: [alsa-sink-Port5 ()] sink.c: Processing rewind...
D: [alsa-sink-Port5 (
)] sink-input.c: Have to rewind 44864 bytes on render memblockq.
D: [alsa-sink-Port5 ()] source.c: Processing rewind...
D: [alsa-sink-Port5 (
)] protocol-native.c: Requesting rewind due to end of underrun.
D: [alsa-sink-Port5 ()] alsa-sink.c: Requested to rewind 65280 bytes.
D: [alsa-sink-Port5 (
)] alsa-sink.c: Limited to 23548 bytes.
D: [alsa-sink-Port5 ()] alsa-sink.c: before: 5887
D: [alsa-sink-Port5 (
)] alsa-sink.c: after: 5887
D: [alsa-sink-Port5 ()] alsa-sink.c: Rewound 23548 bytes.
D: [alsa-sink-Port5 (
)] sink.c: Processing rewind...
D: [alsa-sink-Port5 ()] sink-input.c: Have to rewind 23548 bytes on render memblockq.
D: [alsa-sink-Port5 (
)] source.c: Processing rewind...
I: [alsa-sink-Port5 ()] alsa-sink.c: Scheduling delay of 464.48 ms > 18.38 ms, you might want to investigate this to improve latency...
D: [alsa-sink-Port5 (
)] alsa-util.c: Got POLLERR from ALSA
D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
D: [alsa-sink-Port5 (
)] alsa-util.c: PCM state is SUSPENDED
I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
I: [alsa-sink-Port5 (
)] (alsa-lib)pcm_hw.c: SNDRV_PCM_IOCTL_START failed (-77)
D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLERR from ALSA
D: [alsa-sink-Port5 (
)] alsa-util.c: Got POLLOUT from ALSA
D: [alsa-sink-Port5 ()] alsa-util.c: PCM state is RUNNING
I: [alsa-sink-Port5 (
)] alsa-sink.c: Starting playback.
D: [alsa-sink-Port5 ()] ratelimit.c: 215 events suppressed
D: [alsa-sink-Port5 (
)] alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLERR from ALSA
D: [alsa-sink-Port5 (
)] alsa-util.c: Got POLLOUT from ALSA
D: [alsa-sink-Port5 (*)] alsa-util.c: PCM state is RUNNING

Activity

  1. plbossart commented on Apr 1, 2019

    @plbossart
    Member

    @kv2019i PulseAudio rewind issues, sounds like back to the future, huh :-)

  2. self-assigned this
    on Apr 3, 2019
  3. zhuyingjiang commented on Apr 3, 2019

    @zhuyingjiang

    @kv2019i Could you provide the commit ID of the driver and the firmware? Did you test using PCM512X?

  4. zhuyingjiang commented on Apr 3, 2019

    @zhuyingjiang

    I use :
    linux: f3adfd6
    sof: d7b36bf3e4db4
    the result seems is different:
    pulse.log
    dmesg.log
    @kv2019i
    Could you confirm if it is the same thing you have got?

  5. kv2019i commented on Apr 4, 2019

    @kv2019i
    CollaboratorAuthor

    @zhuyingjiang
    Hmm, I tested now with following
    sof: cbd3e07
    linux: f304b5c

    Can you confirm suspend/resume works with your setup? I.e. run "aplay -D hw:0 foo.wav" and "sudo rtcwake -m mem -s 2" without pulseaudio. That should work ok?

    The pulse log seems pretty similar -- there's a rewind attempt and then failed start:

    A new log I took. Has the same two errors you have also (rewind due to end of underrun) and (Implicit underrun of "ALSA Playback").

    I: [alsa-sink-Port5 (*)] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 (*)] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (*)] protocol-native.c: Requesting rewind due to end of underrun.
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: PCM state is RUNNING
    D: [alsa-sink-Port5 (*)] alsa-sink.c: Requested to rewind 47988 bytes.
    D: [alsa-sink-Port5 (*)] alsa-sink.c: Mhmm, actually there is nothing to rewind.
    I: [alsa-sink-Port5 (*)] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (*)] alsa-util.c: PCM state is RUNNING
    D: [alsa-sink-Port5 (*)] protocol-native.c: Implicit underrun of 'ALSA Playback'
    I: [alsa-sink-Port5 (*)] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (*)] alsa-util.c: Got POLLERR from ALSA
    
  6. kv2019i commented on Apr 4, 2019

    @kv2019i
    CollaboratorAuthor

    @kv2019i Could you provide the commit ID of the driver and the firmware? Did you test using PCM512X?

    Commit-ids are above, and yes, as using PCM512X.

  7. zhuyingjiang commented on Apr 8, 2019

    @zhuyingjiang

    I have test on Up2 with PCM512x, now some time the PCM playback can recover after suspend/resume. but still will have "underrun", not sure if it is caused by this fix.

    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING
    I: [alsa-sink-Port5 ()] alsa-sink.c: Starting playback.
    D: [alsa-sink-Port5 (
    )] alsa-sink.c: hwbuf_unused=0
    D: [alsa-sink-Port5 ()] alsa-sink.c: setting avail_min=15487
    D: [alsa-sink-Port5 (
    )] alsa-util.c: Got POLLERR from ALSA
    D: [alsa-sink-Port5 ()] alsa-util.c: Got POLLOUT from ALSA
    D: [alsa-sink-Port5 (
    )] alsa-util.c: PCM state is RUNNING

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

Metadata

Metadata

Assignees

Labels

bugSomething isn't workingsuspend resumeIssues related to suspend resume (e.g. rtcwake)

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions