janvda / balena-pulseaudio

Is a balena application running a pulseaudio server and demonstrating how it can be used for playing and recording audio on a raspberry pi. It also supports bluetooth audio devices.
Eclipse Public License 2.0
6 stars 2 forks source link

"xcb_connection_has_error() returned true" and it takes minutes to respond on commands #13

Closed janvda closed 5 years ago

janvda commented 5 years ago

It is not clear what happened but since yesterday the application is almost unusable. Restarting/rebooting/purging/switching off bluetooth devices/disconnecting USB devices/ ... didn't make a difference.

Most pulseaudio commands (e.g. pactl list short) take minutes before they respond - even the aplay -l takes a very long time.

The first thing logged after minutes by the command is always the following message

xcb_connection_has_error() returned true

Here an extract of the aplay -l launched in the pulseaudio-server service. So it took minutes bertween logging the line **** List of PLAY...and the next line = xcb_connection_has_error()...

root@ba7c427:/# aplay -l
**** List of PLAYBACK Hardware Devices ****
xcb_connection_has_error() returned true
card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA]
  Subdevices: 6/7
  Subdevice #0: subdevice #0
...

another example (there were also minutes before launching the command the line xcb_connection_has_error() returned true is logged).

root@ba7c427:/# pactl info
xcb_connection_has_error() returned true
Server String: /tmp/pulse-mq2nofTFQMjS/native
Library Protocol Version: 32
Server Protocol Version: 32
Is Local: yes
Client Index: 8
Tile Size: 65496
User Name: root
Host Name: ba7c427
Server Name: pulseaudio
Server Version: 12.2
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: alsa_output.default
Default Source: alsa_input.hw_1_0
Cookie: 1446:fb41
root@ba7c427:/# 
janvda commented 5 years ago

I have checked on branch alpine_pulseaudio_image and there aplay -l immediately returned without the xcb_connection_has_error()... line but I am having the same problems for the pactlcommands.

Here below an extract of the command launched on pulseaudio-server it took around 2 minutes before xcb_connection_has_error()..got logged.

bash-5.0# pactl info
xcb_connection_has_error() returned true
Server String: /tmp/pulse-fihC6f4PdlBc/native
Library Protocol Version: 32
Server Protocol Version: 32
Is Local: yes
Client Index: 0
Tile Size: 65496
User Name: root
Host Name: ba7c427
Server Name: pulseaudio
Server Version: 12.2
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: alsa_output.default
Default Source: alsa_output.default.monitor
Cookie: 8189:9899
bash-5.0# 

The following is seen in the balena log file (note that the logs only appeared after the command returned - so they most likely give no indication what caused the delay).

07.09.19 09:17:54 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Created 0 "Native client (UNIX socket client)"
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Protocol version: remote 32, local 32
07.09.19 09:17:54 (+0200)  pulseaudio-server  I: [pulseaudio] protocol-native.c: Got credentials: uid=0 gid=0 success=1
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: SHM possible: yes
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Negotiated SHM: yes
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Memfd possible: yes
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Negotiated SHM type: shared memfd
07.09.19 09:17:54 (+0200)  pulseaudio-server  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 65496
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] srbchannel.c: SHM block is 65496 bytes, ringbuffer capacity is 2 * 32724 bytes
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Enabling srbchannel...
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] module-augment-properties.c: Looking for .desktop file for pactl
07.09.19 09:17:54 (+0200)  pulseaudio-server  D: [pulseaudio] protocol-native.c: Client enabled srbchannel.
07.09.19 09:17:54 (+0200)  pulseaudio-server  I: [pulseaudio] client.c: Freed 0 "pactl"
07.09.19 09:17:54 (+0200)  pulseaudio-server  I: [pulseaudio] protocol-native.c: Connection died.
janvda commented 5 years ago

Is it because I have set DISPLAY to 192.168.1.5:0 as device environment variable in my balena cloud dashboard ?

... ping is also not immediately responding.

bash-5.0# ping 192.168.1.5
PING 192.168.1.5 (192.168.1.5): 56 data bytes
janvda commented 5 years ago

The problems seems to be caused by my Xquartz server running on macbook (IP address = 192.168.1.5) not accepting those X-connections.

The following changes in terminal window of Xquartz server fixed it (the IP addresses are the 2 IP addresses of my balena device).

bash-3.2$ xhost +192.168.1.58
192.168.1.58 being added to access control list
bash-3.2$ xhost +192.168.1.10
192.168.1.10 being added to access control list
bash-3.2$ 
janvda commented 5 years ago

reinstalling master branch again ... and there it is also fixed thanks to the changes made in previous comment.

janvda commented 5 years ago

Today I have the same issue when DISPLAY is set to 192.168.1.3:0 it took minutes before I saw xcb_connection_has_error() returned true after entering the command pactl info

root@ba7c427:/# pactl info
xcb_connection_has_error() returned true
Server String: /tmp/pulse-Ph5g8FKAvGkE/native
Library Protocol Version: 32
Server Protocol Version: 32
Is Local: yes
Client Index: 2
Tile Size: 65496
User Name: root
Host Name: ba7c427
Server Name: pulseaudio
Server Version: 12.2
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: alsa_output.hw_2_0
Default Source: PS3_eye_camera
Cookie: 5f21:e544
root@ba7c427:/#
janvda commented 5 years ago

The issue in previous comment got fixed by turning Wi-Fi off on my macbookpro (so only using ethernet connection on my macbook) and rechanging back the DISPLAY env variable to 192.168.1.5:0 (strange as according to my mabook Network settings the IP address of USB10/100/1000 Lan is 192.168.1.3).

I also still have xcb_connection_has_error() returned true

root@ba7c427:/# pactl info
xcb_connection_has_error() returned true
Server String: /tmp/pulse-pgsS11tvNJ28/native
Library Protocol Version: 32
Server Protocol Version: 32
Is Local: yes
Client Index: 2
Tile Size: 65496
User Name: root
Host Name: ba7c427
Server Name: pulseaudio
Server Version: 12.2
Default Sample Specification: s16le 2ch 44100Hz
Default Channel Map: front-left,front-right
Default Sink: alsa_output.hw_2_0
Default Source: PS3_eye_camera
Cookie: ceda:2619
root@ba7c427:/# 
janvda commented 5 years ago

Very interesting link:

janvda commented 5 years ago

1/ before starting pulseaudio i have unset DISPLAY 2/ and also doing an unset DISPLAY before running the pactl info made that message xcb_connection_has_error() returned true no longer appeared and I immediately got a response.

janvda commented 5 years ago

So this issue is fixed by assuring that the DISPLAY is not set: nor on the server as on the clients. So in the start scripts of pulseaudio server and pulse audio clients we explicit do an unset DISPLAY.

janvda commented 5 years ago

fixed by pull request #21

shumb commented 4 years ago

I had the same problem on my docker.

yyt-111 commented 11 months ago

I had the same problem on finalshell an ssh tool