pulseaudio overflow (cause or related to kernel freeze?)

Bug #1931976 reported by Mikko Rantalainen
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux-hwe-5.4 (Ubuntu)
New
Undecided
Unassigned

Bug Description

May be related to old bug https://bugzilla.redhat.com/show_bug.cgi?id=485734

The error appeared when system froze for 30-60 seconds (log timestamps before the freeze were earlier so I don't know the exact moment the system froze, only timestamps for the moment it automatically continue to run again).

The only error message found in journalctl was this (hostname is "desktop"):

2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: snd_pcm_delay() returned a value that is exceptionally large: -377464 bytes (-2139 ms).
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: snd_pcm_dump():
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Soft volume PCM
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Control: PCM Playback Volume
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: min_dB: -51
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: max_dB: 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: resolution: 256
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Its setup is:
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: stream : PLAYBACK
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: access : MMAP_INTERLEAVED
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: format : S16_LE
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: subformat : STD
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: channels : 2
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: rate : 44100
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: exact rate : 44100 (44100/1)
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: msbits : 16
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: buffer_size : 16384
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_size : 8192
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_time : 185759
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: tstamp_mode : ENABLE
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: tstamp_type : MONOTONIC
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_step : 1
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: avail_min : 15802
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_event : 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: start_threshold : -1
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: stop_threshold : 4611686018427387904
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: silence_threshold: 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: silence_size : 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: boundary : 4611686018427387904
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Slave: Hardware PCM card 0 'HDA Intel PCH' device 0 subdevice 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Its setup is:
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: stream : PLAYBACK
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: access : MMAP_INTERLEAVED
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: format : S16_LE
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: subformat : STD
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: channels : 2
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: rate : 44100
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: exact rate : 44100 (44100/1)
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: msbits : 16
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: buffer_size : 16384
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_size : 8192
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_time : 185759
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: tstamp_mode : ENABLE
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: tstamp_type : MONOTONIC
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_step : 1
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: avail_min : 15802
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: period_event : 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: start_threshold : -1
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: stop_threshold : 4611686018427387904
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: silence_threshold: 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: silence_size : 0
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: boundary : 4611686018427387904
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: appl_ptr : 667758626
2021-06-14T15:28:59+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: hw_ptr : 667852992
2021-06-14T15:29:02+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write.
2021-06-14T15:29:02+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.
2021-06-14T15:29:02+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.

Note the NEGATIVE output from snd_pcm_delay() which matches the old bug https://bugzilla.redhat.com/show_bug.cgi?id=485734

This happened very near the same time as freeze that I reported in bug 1931871 so I don't know if this is the cause of the kernel freeze or the consequence.

I also had similar error earlier in the same log where the returned value is positive and makes sense for simply having too high latency:

2021-06-14T15:27:25+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: snd_pcm_avail() returned a value that is exceptionally large: 382816 bytes (2170 ms).
2021-06-14T15:27:25+0300 desktop pulseaudio[2472]: [alsa-sink-ALC892 Analog] alsa-util.c: Most likely this is a bug in the ALSA driver 'snd_hda_intel'. Please report this issue to the ALSA developers.

The 2170 ms delay is more than expected if the kernel memory management is frozen as I assume is the cause for https://bugs.launchpad.net/ubuntu/+source/linux-meta-hwe-5.4/+bug/1931871

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: linux-modules-5.4.0-74-lowlatency 5.4.0-74.83~18.04.1
ProcVersionSignature: Ubuntu 5.4.0-74.83~18.04.1-lowlatency 5.4.114
Uname: Linux 5.4.0-74-lowlatency x86_64
ApportVersion: 2.20.9-0ubuntu7.24
Architecture: amd64
CurrentDesktop: MATE
Date: Tue Jun 15 10:22:29 2021
Dependencies:

EcryptfsInUse: Yes
InstallationDate: Installed on 2019-01-05 (891 days ago)
InstallationMedia: Ubuntu 18.04.1 LTS "Bionic Beaver" - Release amd64 (20180725)
SourcePackage: linux-hwe-5.4
UpgradeStatus: No upgrade log present (probably fresh install)

Revision history for this message
Mikko Rantalainen (mira) wrote :
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.