Bug 201437 - snd_usb_audio: snd_pcm_avail() returned a value that is exceptionally large: 1559520 bytes (16245 ms)
Summary: snd_usb_audio: snd_pcm_avail() returned a value that is exceptionally large: ...
Status: NEW
Alias: None
Product: Drivers
Classification: Unclassified
Component: Sound(ALSA) (show other bugs)
Hardware: Intel Linux
: P1 normal
Assignee: Jaroslav Kysela
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-10-16 12:07 UTC by Julien
Modified: 2020-04-01 17:08 UTC (History)
1 user (show)

See Also:
Kernel Version: 4.18.7-arch1-1-ARCH
Subsystem:
Regression: No
Bisected commit-id:

Attachments
Output from alsa-info.sh (81.10 KB, text/plain)
2018-10-16 12:07 UTC, Julien 		Details
Kernel log right after occurence (5.70 KB, text/plain)
2020-04-01 17:05 UTC, n.fabritius 		Details
Add an attachment (proposed patch, testcase, etc.)

Description Julien 2018-10-16 12:07:44 UTC 
Created attachment 279049 [details]
Output from alsa-info.sh

Oct 16 11:10:38 xxxxxx pulseaudio[986]: E: [alsa-sink-USB Audio] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write.
Oct 16 11:10:38 xxxxxx pulseaudio[986]: E: [alsa-sink-USB Audio] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_usb_audio'. Please report this issue to the ALSA developers.
Oct 16 11:10:38 xxxxxx pulseaudio[986]: E: [alsa-sink-USB Audio] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
Oct 16 12:46:55 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:47:08 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:47:12 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:47:32 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 1559520 bytes (16245 ms).
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_usb_audio'. Please report this issue to the ALSA developers.
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_dump():
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Hardware PCM card 3 'SteelSeries Arctis 7' device 0 subdevice 0
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Its setup is:
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stream       : CAPTURE
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   access       : MMAP_INTERLEAVED
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   format       : S16_LE
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   subformat    : STD
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   channels     : 1
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   rate         : 48000
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   exact rate   : 48000 (48000/1)
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   msbits       : 16
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   buffer_size  : 88200
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_size  : 44100
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_time  : 918750
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_mode  : ENABLE
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_type  : MONOTONIC
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_step  : 1
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   avail_min    : 44100
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_event : 0
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   start_threshold  : -1
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stop_threshold   : 6206523236469964800
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   silence_threshold: 0
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   silence_size : 0
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   boundary     : 6206523236469964800
Oct 16 12:47:32 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   appl_ptr     : 333954336
Oct 16 12:47:56 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   hw_ptr       : 334763136
Oct 16 12:47:56 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:47:56 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] ratelimit.c: 26 events suppressed
Oct 16 12:47:56 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:48:54 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:49:22 xxxxxx pulseaudio[986]: W: [alsa-source-USB Audio] asyncq.c: q overrun, queuing locally
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: 11705520 bytes (121932 ms).
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_usb_audio'. Please report this issue to the ALSA developers.
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_dump():
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Hardware PCM card 3 'SteelSeries Arctis 7' device 0 subdevice 0
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Its setup is:
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stream       : CAPTURE
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   access       : MMAP_INTERLEAVED
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   format       : S16_LE
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   subformat    : STD
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   channels     : 1
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   rate         : 48000
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   exact rate   : 48000 (48000/1)
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   msbits       : 16
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   buffer_size  : 88200
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_size  : 44100
Oct 16 12:49:22 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_time  : 918750
Oct 16 12:49:51 xxxxxx kernel: audit: type=1701 audit(1539686990.051:733): auid=1000 uid=1000 gid=1000 ses=2 pid=986 comm="alsa-source-USB" exe="/usr/bin/pulseaudio" sig=6 res=1
Oct 16 12:49:51 xxxxxx kernel: java invoked oom-killer: gfp_mask=0x6200ca(GFP_HIGHUSER_MOVABLE), nodemask=(null), order=0, oom_score_adj=0
Oct 16 12:49:51 xxxxxx kernel: java cpuset=d03035eca48deeee7f9a53fa8f16a99a6f3603fe1aacab48edefbdbdd17bc7d2 mems_allowed=0
Oct 16 12:49:51 xxxxxx kernel: CPU: 2 PID: 28943 Comm: java Tainted: P           O      4.18.7-arch1-1-ARCH #1
Oct 16 12:49:51 xxxxxx kernel: [  986]  1000   986   615568     7485   475136        0             0 pulseaudio
Oct 16 12:49:50 xxxxxx audit[986]: ANOM_ABEND auid=1000 uid=1000 gid=1000 ses=2 pid=986 comm="alsa-source-USB" exe="/usr/bin/pulseaudio" sig=6 res=1
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_mode  : ENABLE
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_type  : MONOTONIC
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_step  : 1
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   avail_min    : 44100
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_event : 0
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   start_threshold  : -1
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stop_threshold   : 6206523236469964800
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   silence_threshold: 0
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   silence_size : 0
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   boundary     : 6206523236469964800
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   appl_ptr     : 334571736
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   hw_ptr       : 340424496
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 11705520 bytes (121932 ms).
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_usb_audio'. Please report this issue to the ALSA developers.
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: snd_pcm_dump():
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Hardware PCM card 3 'SteelSeries Arctis 7' device 0 subdevice 0
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c: Its setup is:
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stream       : CAPTURE
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   access       : MMAP_INTERLEAVED
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   format       : S16_LE
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   subformat    : STD
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   channels     : 1
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   rate         : 48000
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   exact rate   : 48000 (48000/1)
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   msbits       : 16
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   buffer_size  : 88200
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_size  : 44100
Oct 16 12:49:52 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_time  : 918750
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_mode  : ENABLE
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   tstamp_type  : MONOTONIC
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_step  : 1
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   avail_min    : 44100
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   period_event : 0
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   start_threshold  : -1
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   stop_threshold   : 6206523236469964800
Oct 16 12:49:55 xxxxxx pulseaudio[986]: E: [alsa-source-USB Audio] alsa-util.c:   silence_threshold: 0
Comment 1 n.fabritius 2020-04-01 17:05:20 UTC 
Created attachment 288145 [details]
Kernel log right after occurence
Comment 2 n.fabritius 2020-04-01 17:07:08 UTC 
Just hit this bug. I was listening to Soundcloud in Firefox for hours. Also, the machine was quite stressed with parallel compilation.
Comment 3 n.fabritius 2020-04-01 17:08:55 UTC 
Please note the negative return value of snd_pcm_delay() in the attached log:

snd_pcm_delay() returned a value that is exceptionally large: -5991976 bytes (-33968 ms).
Note You need to log in before you can comment on or make changes to this bug.