Skip to main content ↑ ↓
Topic: dinit & pipewire sometimes don't work on boot  (Read 523 times) previous topic - next topic
0 Members and 1 Guest are viewing this topic.

dinit & pipewire sometimes don't work on boot

I followed this: https://wiki.artixlinux.org/Site/PipewireInsteadPulseaudio
Am using xfce and have this file ".config/autostart/dinit_user.desktop"
Code: [Select]
[Desktop Entry]
Version=1.0
Name=user_dinit
Type=Application
Exec=sh -c 'dinit &'
Terminal=false
StartupNotify=false
Hidden=false
Starting my dinit for the user.

Sometimes when I boot up my PC the audio doesn't work, if I reboot once or twice, it starts working. The necessary services are actively running, and restarting them through dinitctl doesn't do anything.
Code: [Select]
[{+}     ] wireplumber (pid: 1546)
[{+}     ] pipewire (pid: 1543)
[{+}     ] dbus (pid: 1523)
[{+}     ] pipewire-pulse (pid: 1545)
My audio output device is my monitor, I don't think this is it?:
Code: [Select]
~> pw-cli ls Device
	id 51, type PipeWire:Interface:Device/3
 		object.serial = "51"
 		factory.id = "15"
 		client.id = "46"
 		device.api = "alsa"
 		device.description = "Built-in Audio"
 		device.name = "alsa_card.pci-0000_00_1f.3"
 		device.nick = "HDA Intel PCH"
 		media.class = "Audio/Device"
~> pactl list short sinks
34	auto_null	PipeWire	float32le 2ch 48000Hz	SUSPENDED
~> pactl list short sources
34	auto_null.monitor	PipeWire	float32le 2ch 48000Hz	SUSPENDED
I'm at quite a loss on how to debug this, any help would be greatly appreciated.

Re: dinit & pipewire sometimes don't work on boot

Reply #1 –
When I have audio it's:
Code: [Select]
~> pactl list short sinks
49	alsa_output.pci-0000_01_00.1.hdmi-stereo-extra3	PipeWire	s32le 2ch 48000Hz	RUNNING
~> pactl list short sources
49	alsa_output.pci-0000_01_00.1.hdmi-stereo-extra3.monitor	PipeWire	s32le 2ch 48000Hz	RUNNING
The little xfce audio icon in the taskbar gets enabled quite late after logging in (~1s), and it feels like if I try to play audio before it gets enabled, that's when I lose audio until rebooting. Though this could be some confirmation bias, I cannot really reproduce consistently.

Re: dinit & pipewire sometimes don't work on boot

Reply #2 –
use turnstile?
But I also want to know how to debug.

Re: dinit & pipewire sometimes don't work on boot

Reply #3 –
okay I'm using turnstile now. The little sound icon seems to be enabled faster now, though the problem persists.

Re: dinit & pipewire sometimes don't work on boot

Reply #4 –
I guess you could do a service that could restart wireplumber, pipewire, pipewire-pulse all together. so then it would be one command to restart them if lost after booting, which should make them work.

I am just learning dinit. perhaps @kiblaster could help?

Re: dinit & pipewire sometimes don't work on boot

Reply #5 –
> I guess you could do a service that could restart wireplumber, pipewire, pipewire-pulse all together. so then it would be one command to restart them if lost after booting, which should make them work.

Unfortunately restarting them doesn't do anything.

Here are the logs:
Code: [Select]
~> dinitctl catlog pipewire
~> dinitctl catlog pipewire-pulse
~> dinitctl catlog wireplumber
N 16:35:39.727110 wp-internal-comp-l ../wireplumber/lib/wp/private/internal-comp-loader.c:945:wp_internal_comp_loader_load: Loading profile 'main'
E 16:35:40.051505            default ../pipewire/spa/plugins/bluez5/upower.c:54:upower_get_percentage_properties_reply: Failed to get percentage from UPower: org.freedesktop.DBus.Error.NameHasNoOwner
N 16:35:40.067596          wp-device ../wireplumber/lib/wp/device.c:630:wp_spa_device_new_from_spa_factory: SPA handle 'api.libcamera.enum.manager' could not be loaded; is it installed?
N 16:35:40.067608 s-monitors-libcame enumerate-device.lua:30:chunk: PipeWire's libcamera SPA plugin is missing or broken. Some camera types may not be supported.
They only seem to report that the extra/pipewire-libcamera package is missing (which is true, I don't have it installed, but my camera works?).

The turnstiled log only has this which might be interesting:
srv: pam_close_session: Error in service module

I saw a glimpse of a fuller message when restarting, it included the words "elogind" and "Cannot connect to bus".

Maybe this is useful (I didn't touch it though):
Code: [Select]
> cat /etc/pam.d/turnstiled
auth		sufficient	pam_rootok.so
session		optional	pam_keyinit.so force revoke
session		optional	pam_umask.so usergroups umask=022
-session	optional	pam_elogind.so
session		required	pam_turnstile.so turnstiled
session		required	pam_limits.so

There are 5 `dbus-deamon` processes running and one `dbus-launch` which might be unusual. After enabling log-buffer for user dbus here it is (during a boot for which sound doesn't work):
 
Code: [Select]
~> dinitctl catlog dbus
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.gtk.vfs.Daemon' requested by ':1.6' (uid=1000 pid=1282 comm="/usr/bin/wireplumber")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.gtk.vfs.Daemon'
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.xfce.Xfconf' requested by ':1.11' (uid=1000 pid=1311 comm="xfce4-session")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.xfce.Xfconf'
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='ca.desrt.dconf' requested by ':1.15' (uid=1000 pid=1407 comm="xfsettingsd --display :0.0 --sm-client-id 24ef0457")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'ca.desrt.dconf'
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.freedesktop.Notifications' requested by ':1.25' (uid=1000 pid=1457 comm="xfce4-power-manager --restart --sm-client-id 2ad92")

(xfce4-notifyd:1479): Gtk-WARNING **: 16:50:02.050: cannot open display: 
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activated service 'org.freedesktop.Notifications' failed: Process org.freedesktop.Notifications exited with status 1
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.freedesktop.Notifications' requested by ':1.21' (uid=1000 pid=1441 comm="/usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/pa")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.xfce.Notifyd' requested by ':1.24' (uid=1000 pid=1443 comm="/usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/pa")

(xfce4-notifyd:1486): Gtk-WARNING **: 16:50:02.078: cannot open display: 
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activated service 'org.freedesktop.Notifications' failed: Process org.freedesktop.Notifications exited with status 1

(xfce4-notifyd:1489): Gtk-WARNING **: 16:50:02.097: cannot open display: 
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.freedesktop.impl.portal.PermissionStore' requested by ':1.8' (uid=1000 pid=1282 comm="/usr/bin/wireplumber")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.freedesktop.portal.Desktop' requested by ':1.38' (uid=1000 pid=1501 comm="flameshot")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.freedesktop.portal.Documents' requested by ':1.39' (uid=1000 pid=1546 comm="/usr/lib/xdg-desktop-portal")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.freedesktop.portal.Documents'

(/usr/lib/xdg-desktop-portal:1546): xdg-desktop-portal-WARNING **: 16:50:02.290: No skeleton to export
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.freedesktop.portal.Desktop'
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Activating service name='org.a11y.Bus' requested by ':1.46' (uid=1000 pid=1694 comm="/opt/spotify/spotify --uri")
dbus-daemon[1271]: [session uid=1000 pid=1271 pidfd=5] Successfully activated service 'org.a11y.Bus'
Here it is when it works:
Code: [Select]
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.gtk.vfs.Daemon' requested by ':1.6' (uid=1000 pid=1374 comm="/usr/bin/wireplumber")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.gtk.vfs.Daemon'
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.xfce.Xfconf' requested by ':1.11' (uid=1000 pid=1401 comm="xfce4-session")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.xfce.Xfconf'
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='ca.desrt.dconf' requested by ':1.15' (uid=1000 pid=1502 comm="xfsettingsd --display :0.0 --sm-client-id 24ef0457")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'ca.desrt.dconf'
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.freedesktop.Notifications' requested by ':1.22' (uid=1000 pid=1534 comm="/usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/pa")

(xfce4-notifyd:1573): Gtk-WARNING **: 16:54:03.902: cannot open display: 
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activated service 'org.freedesktop.Notifications' failed: Process org.freedesktop.Notifications exited with status 1
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.xfce.Notifyd' requested by ':1.23' (uid=1000 pid=1536 comm="/usr/lib/xfce4/panel/wrapper-2.0 /usr/lib/xfce4/pa")

(xfce4-notifyd:1580): Gtk-WARNING **: 16:54:03.970: cannot open display: 
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activated service 'org.xfce.Notifyd' failed: Process org.xfce.Notifyd exited with status 1
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.freedesktop.portal.Desktop' requested by ':1.32' (uid=1000 pid=1591 comm="flameshot")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.freedesktop.portal.Documents' requested by ':1.33' (uid=1000 pid=1614 comm="/usr/lib/xdg-desktop-portal")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.freedesktop.impl.portal.PermissionStore' requested by ':1.34' (uid=1000 pid=1620 comm="/usr/lib/xdg-document-portal")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.freedesktop.portal.Documents'

(/usr/lib/xdg-desktop-portal:1614): xdg-desktop-portal-WARNING **: 16:54:04.238: No skeleton to export
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.freedesktop.portal.Desktop'
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Activating service name='org.a11y.Bus' requested by ':1.43' (uid=1000 pid=1689 comm="/opt/spotify/spotify --uri")
dbus-daemon[1362]: [session uid=1000 pid=1362 pidfd=5] Successfully activated service 'org.a11y.Bus'

Here is the turnstiled error message I see on shutdown:
turnstiled: pam_elogind(turnstiled:session): Failed to connect to system bus: No such file or directory.
There is also:
File descriptor 3 (/dev/console) leaked on vgchange invocation. Parent PID 2423: /bin/sh
though I guess that's unrelated

Re: dinit & pipewire sometimes don't work on boot

Reply #6 –
I did not see any notification from n00b ping.

You could try to add more logging e.g. https://pipewire.pages.freedesktop.org/wireplumber/daemon/logging.html#changing-log-level-at-runtime.
And using pipewire -vvv in the service (and then checking the log).
Code: [Select]
       -v | --verbose
           Increase the verbosity by one level. This option may be specified multiple times.


Re: dinit & pipewire sometimes don't work on boot

Reply #7 –
@kiblaster
Okay I did that, attached are the logs both for a boot that had sound and one which didn't. The logs are reaaally long though so I don't know how to go through them, diffing is non trivial too (difftastic panics even (: ).

Interesting perhaps are the mentions of "alsa_output.pci-0000_01_00.1.hdmi-stereo-extra3" in the files, though I don't really know what to make of them. It is weird (expected?) for example that there are mentions of it in pipewire.log.working , but none in pipewire.log.notworking .