You are not logged in.

#1 2021-07-20 04:16:57

syz
Member
Registered: 2021-07-20
Posts: 1

Pulseaudio randomly increases volume to 200% and freezes

Hi all,

I've recently installed Archlinux on my new Thinkpad T14 Gen 1 AMD. I'm using i3wm and everything seems to work fine, except I've run into issues with the audio (Pulseaudio + ALSA):

99% of the time the audio works without a hitch for music. But roughly once every few hours, upon changing the volume using the laptop vol up/down keys, it appears that something gets stuck in a loop and the volume either gets sent to 0% or over 200%. Simultaneously, the system locks up (cannot see or move cursor, or otherwise interact with open panes). Interestingly, however, the i3 controls for changing focus between panes still work.

I found that I could unfreeze the system by doing a Ctrl-Alt-Fn into a console and then going back.

To investigate this issue, I ran `pulseaudio -vvvvv > ~/pulseaudio.log 2>& 1` to record debug output. After several hours of playing music, the issue manifested. I've included part of the logfile here.

I: [pulseaudio] client.c: Created 441 "Native client (UNIX socket client)"
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client added for object /org/pulseaudio/core1/client441
D: [pulseaudio] protocol-native.c: Protocol version: remote 34, local 34
I: [pulseaudio] protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
D: [pulseaudio] protocol-native.c: SHM possible: yes
D: [pulseaudio] protocol-native.c: Negotiated SHM: yes
D: [pulseaudio] protocol-native.c: Memfd possible: yes
D: [pulseaudio] protocol-native.c: Negotiated SHM type: shared memfd
D: [pulseaudio] memblock.c: Using shared memfd memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65472
D: [pulseaudio] srbchannel.c: SHM block is 65472 bytes, ringbuffer capacity is 2 * 32712 bytes
D: [pulseaudio] protocol-native.c: Enabling srbchannel...
D: [pulseaudio] module-augment-properties.c: Looking for .desktop file for pactl
D: [pulseaudio] protocol-native.c: Client enabled srbchannel.
D: [pulseaudio] protocol-native.c: Client pactl changes volume of sink alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink.
D: [pulseaudio] sink.c: The reference volume of sink alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink changed from front-left: 112466 / 172% / 14.07 dB,   front-right: 112466 / 172% / 14.07 dB to front-left: 119019 / 182% / 15.55 dB,   front-right: 119019 / 182% / 15.55 dB.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Requested volume: front-left: 119019 / 182% / 15.55 dB,   front-right: 119019 / 182% / 15.55 dB
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Got hardware volume: front-left: 65536 / 100% / 0.00 dB,   front-right: 65536 / 100% / 0.00 dB
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Calculated software volume: front-left: 119019 / 182% / 15.55 dB,   front-right: 119019 / 182% / 15.55 dB (accurate-enough=no)
D: [alsa-sink-ALC257 Analog] sink.c: Volume not changing
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Requested to rewind 172872 bytes.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Limited to 165164 bytes.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: before: 41291
D: [alsa-sink-ALC257 Analog] alsa-sink.c: after: 41291
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Rewound 165164 bytes.
D: [alsa-sink-ALC257 Analog] sink.c: Processing rewind...
D: [alsa-sink-ALC257 Analog] sink.c: latency = 2166
D: [alsa-sink-ALC257 Analog] sink-input.c: Have to rewind 165164 bytes on render memblockq.
D: [alsa-sink-ALC257 Analog] source.c: Processing rewind...
I: [pulseaudio] module-device-restore.c: Storing volume/mute for device+port sink:alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink:[Out] Speaker.
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client removed from object /org/pulseaudio/core1/client441
I: [pulseaudio] client.c: Freed 441 "pactl"
I: [pulseaudio] protocol-native.c: Connection died.

The interesting line to me is `sink.c: Volume not changing`, despite the fact that the above code occurs 5-6 times and eventually pushes the volume to ~200%. Perhaps for some reason, a volume increase is not being registered, and Pulseaudio is repeatedly requesting the increase?
For comparison, I also logged debug output for a 'normal' volume change, which looks pretty normal: 'Volume going up to ...'

I: [pulseaudio] client.c: Created 44 "Native client (UNIX socket client)"
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client added for object /org/pulseaudio/core1/client44
D: [pulseaudio] protocol-native.c: Protocol version: remote 34, local 34
I: [pulseaudio] protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
D: [pulseaudio] protocol-native.c: SHM possible: yes
D: [pulseaudio] protocol-native.c: Negotiated SHM: yes
D: [pulseaudio] protocol-native.c: Memfd possible: yes
D: [pulseaudio] protocol-native.c: Negotiated SHM type: shared memfd
D: [pulseaudio] memblock.c: Using shared memfd memory pool with 1024 slots of size 64.0 KiB each, total size is 64.0 MiB, maximum usable slot size is 65472
D: [pulseaudio] srbchannel.c: SHM block is 65472 bytes, ringbuffer capacity is 2 * 32712 bytes
D: [pulseaudio] protocol-native.c: Enabling srbchannel...
D: [pulseaudio] module-augment-properties.c: Looking for .desktop file for pactl
D: [pulseaudio] protocol-native.c: Client enabled srbchannel.
D: [pulseaudio] protocol-native.c: Client pactl changes volume of sink alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink.
D: [pulseaudio] sink.c: The reference volume of sink alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink changed from front-left: 33803 /  52% / -17.25 dB,   front-right: 33803 /  52% / -17.25 dB to front-left: 40356 /  62% / -12.63 dB,   front-right: 40356 /  62% / -12.63 dB.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Requested volume: front-left: 40356 /  62% / -12.63 dB,   front-right: 40356 /  62% / -12.63 dB
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Got hardware volume: front-left: 41350 /  63% / -12.00 dB,   front-right: 41350 /  63% / -12.00 dB
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Calculated software volume: front-left: 63961 /  98% / -0.63 dB,   front-right: 63961 /  98% / -0.63 dB (accurate-enough=no)
D: [alsa-sink-ALC257 Analog] sink.c: Volume going up to 41350 at 51420178485
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Requested to rewind 4096 bytes.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Limited to 3104 bytes.
D: [alsa-sink-ALC257 Analog] alsa-sink.c: before: 776
D: [alsa-sink-ALC257 Analog] alsa-sink.c: after: 776
D: [alsa-sink-ALC257 Analog] alsa-sink.c: Rewound 3104 bytes.
D: [alsa-sink-ALC257 Analog] sink.c: Processing rewind...
D: [alsa-sink-ALC257 Analog] sink.c: latency = 2148
D: [alsa-sink-ALC257 Analog] sink-input.c: Have to rewind 3104 bytes on render memblockq.
D: [alsa-sink-ALC257 Analog] source.c: Processing rewind...
I: [pulseaudio] module-device-restore.c: Storing volume/mute for device+port sink:alsa_output.pci-0000_07_00.6.HiFi___ucm0003.hw_Generic_1__sink:[Out] Speaker.
D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Client removed from object /org/pulseaudio/core1/client44
I: [pulseaudio] client.c: Freed 44 "pactl"
I: [pulseaudio] protocol-native.c: Connection died.

Edit: for reference, the config for volup/down in ~/.config/i3/config is the default i3 config, as far as I'm aware

# Use pactl to adjust volume in PulseAudio.
# set $refresh_i3status killall -SIGUSR1 i3status                                                                                                                                                                  
bindsym XF86AudioRaiseVolume exec --no-startup-id pactl set-sink-volume @DEFAULT_SINK@ +10% && $refresh_i3status
bindsym XF86AudioLowerVolume exec --no-startup-id pactl set-sink-volume @DEFAULT_SINK@ -10% && $refresh_i3status
bindsym XF86AudioMute exec --no-startup-id pactl set-sink-mute @DEFAULT_SINK@ toggle && $refresh_i3status
bindsym XF86AudioMicMute exec --no-startup-id pactl set-source-mute @DEFAULT_SOURCE@ toggle && $refresh_i3status

Any input would be much appreciated here -- since the issue only shows up once every few hours, it's difficult for me to reproduce. I'm happy to provide more log files if needed.

Thanks!

Last edited by syz (2021-07-20 04:21:13)

Offline

Board footer

Powered by FluxBB