🐛 No startsound hifiberry

Bug

What I did

i.e. I installed the raspberry pi with above mentioned buster image and ran the installer script
What happened

With the audio jack I got the start sound as soon as I use my hifiberry there is no startsound. Spotify works (besides the rescan bug).
Further information that might help

Nov 30 23:04:00 raspberrypi systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Nov 30 23:04:00 raspberrypi systemd[1]: Starting User Login Management...
Nov 30 23:04:00 raspberrypi bash[434]: Phoniebox is starting...
Nov 30 23:04:00 raspberrypi kernel: [    6.738756] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.787994] Registered IR keymap rc-cec
Nov 30 23:04:00 raspberrypi kernel: [    6.788188] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1
Nov 30 23:04:00 raspberrypi kernel: [    6.788426] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input7
Nov 30 23:04:00 raspberrypi kernel: [    6.793867] vc4-drm gpu: bound fef05700.hdmi (ops vc4_hdmi_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.794312] vc4-drm gpu: bound fe004000.txp (ops vc4_txp_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.794687] vc4-drm gpu: bound fe206000.pixelvalve (ops vc4_crtc_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.795066] vc4-drm gpu: bound fe207000.pixelvalve (ops vc4_crtc_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.795419] vc4-drm gpu: bound fe20a000.pixelvalve (ops vc4_crtc_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.795708] vc4-drm gpu: bound fe216000.pixelvalve (ops vc4_crtc_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.796011] vc4-drm gpu: bound fec12000.pixelvalve (ops vc4_crtc_ops [vc4])
Nov 30 23:04:00 raspberrypi kernel: [    6.863063] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0
Nov 30 23:04:00 raspberrypi kernel: [    6.863260] vc4-drm gpu: [drm] Cannot find any crtc or sizes
Nov 30 23:04:00 raspberrypi kernel: [    6.914931] random: crng init done
Nov 30 23:04:00 raspberrypi kernel: [    6.914951] random: 7 urandom warning(s) missed due to ratelimiting
Nov 30 23:04:00 raspberrypi kernel: [    7.567118] uart-pl011 fe201000.serial: no DMA platform data
Nov 30 23:04:00 raspberrypi kernel: [    7.815265] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
Nov 30 23:04:00 raspberrypi kernel: [    8.211281] 8021q: 802.1Q VLAN Support v1.8
Nov 30 23:04:00 raspberrypi cleanshutd[412]: Starting...
Nov 30 23:04:00 raspberrypi bash[467]: 2.3
Nov 30 23:04:00 raspberrypi avahi-daemon[411]: Successfully called chroot().
Nov 30 23:04:00 raspberrypi dphys-swapfile[421]: want /var/swap=100MByte, checking existing: keeping it
Nov 30 23:04:00 raspberrypi systemd[1]: Starting triggerhappy global hotkey daemon...
Nov 30 23:04:00 raspberrypi thd[468]: Found socket passed from systemd
Nov 30 23:04:00 raspberrypi bash[469]: AUDIOFOLDERSPATH="/home/pi/RPi-Jukebox-RFID/shared/audiofolders"
Nov 30 23:04:01 raspberrypi bash[469]: PLAYLISTSFOLDERPATH="/home/pi/RPi-Jukebox-RFID/playlists"
Nov 30 23:04:01 raspberrypi bash[469]: SWIPEORPLACE="SWIPENOTPLACE"
Nov 30 23:04:01 raspberrypi bash[469]: SECONDSWIPE="RESTART"
Nov 30 23:04:01 raspberrypi bash[469]: SECONDSWIPEPAUSE="2"
Nov 30 23:04:01 raspberrypi bash[469]: SECONDSWIPEPAUSECONTROLS="ON"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOIFACENAME="Master"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOIFACEACTIVE="0"
Nov 30 23:04:01 raspberrypi bash[469]: VOLUMEMANAGER="mpd"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOVOLCHANGESTEP="3"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOVOLMAXLIMIT="100"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOVOLMINLIMIT="1"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOVOLSTARTUP="30"
Nov 30 23:04:01 raspberrypi bash[469]: AUDIOVOLBOOT="30"
Nov 30 23:04:01 raspberrypi bash[469]: VOLCHANGEIDLE="TRUE"
Nov 30 23:04:01 raspberrypi bash[469]: IDLETIMESHUTDOWN="0"
Nov 30 23:04:01 raspberrypi bash[469]: POWEROFFCMD="sudo poweroff"
Nov 30 23:04:01 raspberrypi bash[469]: SHOWCOVER="ON"
Nov 30 23:04:01 raspberrypi bash[469]: READWLANIPYN="OFF"
Nov 30 23:04:01 raspberrypi bash[469]: EDITION="plusSpotify"
Nov 30 23:04:01 raspberrypi bash[469]: LANG="en-UK"
Nov 30 23:04:01 raspberrypi bash[469]: VERSION="2.3 - 2425890 - master"
Nov 30 23:04:01 raspberrypi bash[469]: CHAPTEREXTENSIONS="mp4,m4a,m4b,m4r"
Nov 30 23:04:01 raspberrypi bash[469]: CHAPTERMINDURATION="600"
Nov 30 23:04:01 raspberrypi bash[469]: CMDVOLUP=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDVOLDOWN=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDNEXT=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDPREV=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDREWIND=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDSEEKFORW=""
Nov 30 23:04:01 raspberrypi bash[469]: CMDSEEKBACK=""
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Successfully dropped remaining capabilities.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Disk Manager...
Nov 30 23:04:01 raspberrypi bash[434]: 30 is the mpd startup volume
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: No service file found in /etc/avahi/services.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting WPA supplicant...
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Joining mDNS multicast group on interface lo.IPv6 with address ::1.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: New relevant interface lo.IPv6 for mDNS.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Deferred execution scheduler.
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1.
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Check for glamor.
Nov 30 23:04:01 raspberrypi dhcpcd[529]: dev: loaded udev
Nov 30 23:04:01 raspberrypi dhcpcd[529]: forked to background, child pid 569
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: New relevant interface lo.IPv4 for mDNS.
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Check for v3d driver.
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Network interface enumeration completed.
Nov 30 23:04:01 raspberrypi systemd[1]: Started System Logging Service.
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Registering new address record for ::1 on lo.*.
Nov 30 23:04:01 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Nov 30 23:04:01 raspberrypi rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.2102.0]
Nov 30 23:04:01 raspberrypi systemd-udevd[183]: event2: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Nov 30 23:04:01 raspberrypi rsyslogd: [origin software="rsyslogd" swVersion="8.2102.0" x-pid="444" x-info="https://www.rsyslog.com"] start
Nov 30 23:04:01 raspberrypi systemd[1]: e2scrub_reap.service: Succeeded.
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Registering new address record for 127.0.0.1 on lo.IPv4.
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Remove Stale Online ext4 Metadata Check Snapshots.
Nov 30 23:04:01 raspberrypi rngd[547]: rngd 2.2 starting up...
Nov 30 23:04:01 raspberrypi systemd[1]: Started LSB: Monitoring GPIO shutdown trigger.
Nov 30 23:04:01 raspberrypi wpa_supplicant[476]: Successfully initialized wpa_supplicant
Nov 30 23:04:01 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Nov 30 23:04:01 raspberrypi raspi-config[435]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Nov 30 23:04:01 raspberrypi rngd[547]: entropy feed to the kernel ready
Nov 30 23:04:01 raspberrypi systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Nov 30 23:04:01 raspberrypi dhcpcd[529]: dev: loaded udev
Nov 30 23:04:01 raspberrypi avahi-daemon[411]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 1947781255.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting DHCP Client Daemon...
Nov 30 23:04:01 raspberrypi dhcpcd[529]: forked to background, child pid 569
Nov 30 23:04:01 raspberrypi systemd[1]: Started User Login Management.
Nov 30 23:04:01 raspberrypi kernel: [    9.060410] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
Nov 30 23:04:01 raspberrypi systemd[1]: Finished dphys-swapfile - set up, mount/unmount, and delete a swap file.
Nov 30 23:04:01 raspberrypi udisksd[474]: udisks daemon version 2.9.2 starting
Nov 30 23:04:01 raspberrypi bash[784]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 34: echo: write error: Broken pipe
Nov 30 23:04:01 raspberrypi systemd[1]: Started LSB: rng-tools (Debian variant).
Nov 30 23:04:01 raspberrypi systemd[1]: Started WPA supplicant.
Nov 30 23:04:01 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=474 comm="/usr/libexec/udisks2/udisksd ")
Nov 30 23:04:01 raspberrypi systemd[1]: Reached target Network.
Nov 30 23:04:01 raspberrypi systemd-udevd[171]: event1: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting CUPS Scheduler...
Nov 30 23:04:01 raspberrypi systemd[1]: Started Phoniebox GPIO Control Service.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Phoniebox Idle Watchdog Service.
Nov 30 23:04:01 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Nov 30 23:04:01 raspberrypi dhcpcd-run-hooks[659]: wlan0: starting wpa_supplicant
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Permit User Sessions...
Nov 30 23:04:01 raspberrypi systemd[1]: Started VNC Server in Service Mode daemon.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Phoniebox RFID-Reader Service.
Nov 30 23:04:01 raspberrypi polkitd[651]: started daemon version 0.105 using authority implementation `local' version `0.105'
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Permit User Sessions.
Nov 30 23:04:01 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Light Display Manager...
Nov 30 23:04:01 raspberrypi systemd[1]: Started DHCP Client Daemon.
Nov 30 23:04:01 raspberrypi systemd[1]: Reached target Network is Online.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting LSB: exim Mail Transport Agent...
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Lighttpd Daemon...
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Mopidy music server...
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Samba NMB Daemon...
Nov 30 23:04:01 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Nov 30 23:04:01 raspberrypi systemd[1]: Started Mopidy music server.
Nov 30 23:04:01 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Hold until boot process finishes up...
Nov 30 23:04:01 raspberrypi udisksd[474]: failed to load module crypto: libbd_crypto.so.2: cannot open shared object file: No such file or directory
Nov 30 23:04:01 raspberrypi udisksd[474]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
Nov 30 23:04:01 raspberrypi systemd[1]: Condition check resulted in Manage Sound Card State (restore and store) being skipped.
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Save/Restore Sound Card State...
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Save/Restore Sound Card State.
Nov 30 23:04:01 raspberrypi systemd[1]: Reached target Sound Card.
Nov 30 23:04:01 raspberrypi udisksd[474]: Failed to load the 'mdraid' libblockdev plugin
Nov 30 23:04:01 raspberrypi udisksd[474]: Failed to load the 'crypto' libblockdev plugin
Nov 30 23:04:01 raspberrypi systemd[1]: Starting Authorization Manager...
Nov 30 23:04:01 raspberrypi lightdm[567]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov 30 23:04:01 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Nov 30 23:04:01 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Nov 30 23:04:01 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 176 (plymouthd).
Nov 30 23:04:01 raspberrypi systemd[1]: Finished Hold until boot process finishes up.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Getty on tty1.
Nov 30 23:04:01 raspberrypi systemd[1]: Reached target Login Prompts.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Light Display Manager.
Nov 30 23:04:01 raspberrypi systemd[1]: Started Authorization Manager.
Nov 30 23:04:01 raspberrypi dhcpcd[569]: wlan0: connected to Access Point `'
Nov 30 23:04:01 raspberrypi dhcpcd[569]: eth0: waiting for carrier
Nov 30 23:04:02 raspberrypi dhcpcd[569]: wlan0: waiting for carrier
Nov 30 23:04:02 raspberrypi kernel: [    9.343904] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
Nov 30 23:04:02 raspberrypi kernel: [    9.344744] bcmgenet fd580000.ethernet eth0: Link is Down
Nov 30 23:04:02 raspberrypi systemd[1]: Started Disk Manager.
Nov 30 23:04:02 raspberrypi udisksd[474]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Nov 30 23:04:02 raspberrypi systemd[1]: Started CUPS Scheduler.
Nov 30 23:04:02 raspberrypi systemd[1]: Started Make remote CUPS printers available locally.
Nov 30 23:04:02 raspberrypi vncserver-x11[583,root]: ServerManager: Server started
Nov 30 23:04:02 raspberrypi exim4[571]: Starting MTA: exim4.
Nov 30 23:04:02 raspberrypi systemd[1]: Started LSB: exim Mail Transport Agent.
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]: BOOTLOADER: up to date
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:    CURRENT: Thu 29 Apr 16:11:25 UTC 2021 (1619712685)
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:     LATEST: Thu 29 Apr 16:11:25 UTC 2021 (1619712685)
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:    RELEASE: default (/lib/firmware/raspberrypi/bootloader/default)
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:             Use raspi-config to change the release.
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:   VL805_FW: Dedicated VL805 EEPROM
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:      VL805: up to date
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:    CURRENT: 000138a1
Nov 30 23:04:02 raspberrypi rpi-eeprom-update[441]:     LATEST: 000138a1
Nov 30 23:04:02 raspberrypi systemd[1]: Finished Check for Raspberry Pi EEPROM updates.
Nov 30 23:04:02 raspberrypi vncserver-x11[583,root]: ConsoleDisplay: Cannot find a running X server on vt1
Nov 30 23:04:02 raspberrypi vncserver-x11[583,root]: ConsoleDisplay: Found running X server (pid=690, binary=/usr/lib/xorg/Xorg)
Nov 30 23:04:02 raspberrypi lighttpd[572]: 2021-11-30 23:04:01: configfile.c.461) Warning: "mod_compress" is DEPRECATED and has been replaced with "mod_deflate".  A future release of lighttpd 1.4.x will not contain mod_compress and lighttpd may fail to start up
Nov 30 23:04:02 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:GPIO Started
Nov 30 23:04:02 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:['Volume0', 'VolumeUp', 'VolumeDown', 'NextSong', 'PrevSong', 'Halt']
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:Device Volume0 not enabled
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:adding GPIO-Device, VolumeUp
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:adding GPIO-Device, VolumeDown
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:adding GPIO-Device, NextSong
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:adding GPIO-Device, PrevSong
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:Device Halt not enabled
Nov 30 23:04:03 raspberrypi PhonieboxGPIOControl[552]: INFO:__main__:Ready for taking actions
Nov 30 23:04:03 raspberrypi lighttpd[572]: 2021-11-30 23:04:01: mod_deflate.c.567) DEPRECATED: compress.filetype replaced with deflate.mimetypes
Nov 30 23:04:03 raspberrypi lighttpd[572]: 2021-11-30 23:04:01: mod_deflate.c.580) DEPRECATED: compress.cache-dir replaced with deflate.cache-dir
Nov 30 23:04:03 raspberrypi systemd[1]: Started Lighttpd Daemon.
Nov 30 23:04:03 raspberrypi bash[1393]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 34: echo: write error: Broken pipe
Nov 30 23:04:03 raspberrypi daemon_rfid_reader.py[563]: 2021-11-30 23:04:03,413 - root - INFO - Dir_PATH: /home/pi/RPi-Jukebox-RFID/scripts
Nov 30 23:04:03 raspberrypi bash[1415]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 34: echo: write error: Broken pipe
Nov 30 23:04:03 raspberrypi bash[1425]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 34: echo: write error: Broken pipe
Nov 30 23:04:03 raspberrypi lighttpd[1287]: 2021-11-30 23:04:03: configfile.c.461) Warning: "mod_compress" is DEPRECATED and has been replaced with "mod_deflate".  A future release of lighttpd 1.4.x will not contain mod_compress and lighttpd may fail to start up
Nov 30 23:04:05 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Nov 30 23:04:06 raspberrypi lightdm[2451]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Nov 30 23:04:06 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Nov 30 23:04:06 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Nov 30 23:04:06 raspberrypi systemd[1]: Finished User Runtime Directory /run/user/1000.
Nov 30 23:04:06 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Nov 30 23:04:06 raspberrypi systemd[2537]: gpgconf: error running '/usr/lib/gnupg/scdaemon': probably not installed
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.__main__ Starting Mopidy 3.2.0
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.config Loading config from builtin defaults
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.config Loading config from file:///usr/share/mopidy/conf.d/mopidy-local.conf
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.config Loading config from file:///usr/share/mopidy/conf.d/mopidy.conf
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.config Loading config from file:///etc/mopidy/mopidy.conf
Nov 30 23:04:06 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.config Loading config from command line options
Nov 30 23:04:06 raspberrypi mopidy[579]: ERROR    [MainThread] mopidy.internal.log Loading logging config '/etc/mopidy/logging.conf' failed. 'formatters'
Nov 30 23:04:06 raspberrypi systemd-xdg-autostart-generator[2646]: Configuration file /etc/xdg/autostart/pprompt.desktop is marked executable. Please remove executable permission bits. Proceeding anyway.
Nov 30 23:04:06 raspberrypi systemd[2508]: Queued start job for default target Main User Target.
Nov 30 23:04:06 raspberrypi systemd[2508]: Created slice User Application Slice.
Nov 30 23:04:06 raspberrypi kernel: [   14.247101] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Nov 30 23:04:06 raspberrypi dhcpcd[569]: wlan0: carrier acquired
Nov 30 23:04:06 raspberrypi systemd[2508]: Reached target Paths.
Nov 30 23:04:06 raspberrypi dhcpcd[569]: wlan0: connected to Access Point `Oase'
Nov 30 23:04:06 raspberrypi systemd[2508]: Reached target Timers.
Nov 30 23:04:06 raspberrypi dhcpcd[569]: DUID 00:01:00:01:29:0f:ea:db:dc:a6:32:3f:6b:f7
Nov 30 23:04:06 raspberrypi systemd[2508]: Starting D-Bus User Message Bus Socket.
Nov 30 23:04:06 raspberrypi dhcpcd[569]: wlan0: IAID 32:3f:6b:f8
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on GnuPG network certificate management daemon.
Nov 30 23:04:06 raspberrypi dhcpcd[569]: wlan0: adding address fe80::a8d9:1388:54e6:bc66
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on Multimedia System.
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on debconf communication socket.
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on Sound System.
Nov 30 23:04:06 raspberrypi systemd[2508]: Listening on D-Bus User Message Bus Socket.
Nov 30 23:04:06 raspberrypi systemd[2508]: Reached target Sockets.
Nov 30 23:04:06 raspberrypi systemd[2508]: Reached target Basic System.
Nov 30 23:04:06 raspberrypi systemd[1]: Started User Manager for UID 1000.
Nov 30 23:04:06 raspberrypi systemd[1]: Started Session 1 of user pi.
Nov 30 23:04:06 raspberrypi systemd[2508]: Started Multimedia Service.
Nov 30 23:04:06 raspberrypi systemd[1]: Started Session 3 of user pi.
Nov 30 23:04:06 raspberrypi systemd[2508]: Starting Sound Service...
Nov 30 23:04:06 raspberrypi avahi-daemon[411]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::a8d9:1388:54e6:bc66.
Nov 30 23:04:06 raspberrypi avahi-daemon[411]: New relevant interface wlan0.IPv6 for mDNS.
Nov 30 23:04:06 raspberrypi avahi-daemon[411]: Registering new address record for fe80::a8d9:1388:54e6:bc66 on wlan0.*.
Nov 30 23:04:06 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.18' (uid=1000 pid=2762 comm="/usr/bin/pipewire ")
Nov 30 23:04:07 raspberrypi systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Nov 30 23:04:07 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Nov 30 23:04:07 raspberrypi systemd[1]: Started RealtimeKit Scheduling Policy Service.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully called chroot.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully dropped privileges.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully limited resources.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Running.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Canary thread running.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Watchdog thread running.
Nov 30 23:04:07 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.__main__ Enabled extensions: file, iris, spotify, local, softwaremixer, http, stream, mpd, m3u
Nov 30 23:04:07 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.__main__ Disabled extensions: none
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 2762 of process 2762 owned by '1000' high priority at nice level -11.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 1 threads of 1 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 2763 of process 2763 owned by '1000' high priority at nice level -11.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 2 threads of 2 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 2 threads of 2 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 2 threads of 2 processes of 1 users.
Nov 30 23:04:07 raspberrypi dhcpcd[569]: wlan0: rebinding lease of 192.168.5.54
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 2769 of process 2762 owned by '1000' RT at priority 20.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 3 threads of 2 processes of 1 users.
Nov 30 23:04:07 raspberrypi systemd[2508]: Started D-Bus User Message Bus.
Nov 30 23:04:07 raspberrypi pipewire[2762]: Failed to receive portal pid: org.freedesktop.DBus.Error.NameHasNoOwner: Could not get PID of name 'org.freedesktop.portal.Desktop': no such name
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 2833 of process 2833 owned by '1000' high priority at nice level -11.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 4 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 4 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 4 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 2848 of process 2833 owned by '1000' RT at priority 20.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 5 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi dhcpcd[569]: wlan0: soliciting an IPv6 router
Nov 30 23:04:07 raspberrypi kernel: [   15.044936] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.046079] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.046854] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.063156] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.063607] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.064017] hdmi-audio-codec hdmi-audio-codec.5.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi pulseaudio[2763]: Failed to find a working profile.
Nov 30 23:04:07 raspberrypi pulseaudio[2763]: Failed to load module "module-alsa-card" (argument: "device_id="1" name="platform-fef00700.hdmi" card_name="alsa_card.platform-fef00700.hdmi" namereg_fail=false tsched=no fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1""): initialization failed.
Nov 30 23:04:07 raspberrypi kernel: [   15.107692] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.108470] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.109271] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.119835] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.120350] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi kernel: [   15.120852] hdmi-audio-codec hdmi-audio-codec.6.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
Nov 30 23:04:07 raspberrypi pulseaudio[2763]: Failed to find a working profile.
Nov 30 23:04:07 raspberrypi pulseaudio[2763]: Failed to load module "module-alsa-card" (argument: "device_id="2" name="platform-fef05700.hdmi" card_name="alsa_card.platform-fef05700.hdmi" namereg_fail=false tsched=no fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1""): initialization failed.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 5 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Successfully made thread 3060 of process 2763 owned by '1000' RT at priority 5.
Nov 30 23:04:07 raspberrypi rtkit-daemon[2775]: Supervising 6 threads of 3 processes of 1 users.
Nov 30 23:04:07 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.23' (uid=1000 pid=2763 comm="/usr/bin/pulseaudio --daemonize=no --log-target=jo")
Nov 30 23:04:07 raspberrypi systemd[1]: Condition check resulted in Bluetooth service being skipped.
Nov 30 23:04:07 raspberrypi systemd[2508]: Started Sound Service.
Nov 30 23:04:07 raspberrypi systemd[2508]: Reached target Main User Target.
Nov 30 23:04:07 raspberrypi systemd[2508]: Startup finished in 1.637s.
Nov 30 23:04:08 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting Mopidy mixer: SoftwareMixer
Nov 30 23:04:08 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Mixer volume set to 30
Nov 30 23:04:08 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting Mopidy audio
Nov 30 23:04:08 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting Mopidy backends: FileBackend, M3UBackend, StreamBackend, SpotifyBackend, LocalBackend
Nov 30 23:04:08 raspberrypi mopidy[579]: INFO     [Audio-2] mopidy.audio.actor Audio output set to "alsasink"
Nov 30 23:04:08 raspberrypi mopidy[579]: ERROR    [SpotifyEventLoop] spotify.session Spotify login error: <ErrorType.OTHER_PERMANENT: 10>
Nov 30 23:04:08 raspberrypi bash[3553]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 34: echo: write error: Broken pipe
Nov 30 23:04:09 raspberrypi kernel: [   16.698209] Bluetooth: Core ver 2.22
Nov 30 23:04:09 raspberrypi kernel: [   16.698275] NET: Registered protocol family 31
Nov 30 23:04:09 raspberrypi kernel: [   16.698282] Bluetooth: HCI device and connection manager initialized
Nov 30 23:04:09 raspberrypi kernel: [   16.699519] Bluetooth: HCI socket layer initialized
Nov 30 23:04:09 raspberrypi kernel: [   16.699532] Bluetooth: L2CAP socket layer initialized
Nov 30 23:04:09 raspberrypi kernel: [   16.699552] Bluetooth: SCO socket layer initialized
Nov 30 23:04:09 raspberrypi kernel: [   16.723920] Bluetooth: HCI UART driver ver 2.3
Nov 30 23:04:09 raspberrypi kernel: [   16.723932] Bluetooth: HCI UART protocol H4 registered
Nov 30 23:04:09 raspberrypi kernel: [   16.723986] Bluetooth: HCI UART protocol Three-wire (H5) registered
Nov 30 23:04:09 raspberrypi kernel: [   16.724158] Bluetooth: HCI UART protocol Broadcom registered
Nov 30 23:04:09 raspberrypi btuart[491]: bcm43xx_init
Nov 30 23:04:09 raspberrypi btuart[491]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd
Nov 30 23:04:09 raspberrypi btuart[491]: Set Controller UART speed to 3000000 bit/s
Nov 30 23:04:09 raspberrypi btuart[491]: Device setup complete
Nov 30 23:04:09 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Nov 30 23:04:09 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Nov 30 23:04:09 raspberrypi systemd[2508]: Reached target Bluetooth.
Nov 30 23:04:09 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Nov 30 23:04:09 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Nov 30 23:04:09 raspberrypi systemd[1]: Starting Raspberry Pi bluetooth helper...
Nov 30 23:04:09 raspberrypi bthelper[3833]: Raspberry Pi BDADDR already set
Nov 30 23:04:09 raspberrypi systemd[1]: Finished Raspberry Pi bluetooth helper.
Nov 30 23:04:09 raspberrypi systemd[1]: Starting Bluetooth service...
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: Bluetooth daemon 5.55
Nov 30 23:04:09 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.bluez'
Nov 30 23:04:09 raspberrypi systemd[1]: Started Bluetooth service.
Nov 30 23:04:09 raspberrypi systemd[1]: Reached target Bluetooth.
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: Starting SDP server
Nov 30 23:04:09 raspberrypi kernel: [   17.093906] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Nov 30 23:04:09 raspberrypi kernel: [   17.093915] Bluetooth: BNEP filters: protocol multicast
Nov 30 23:04:09 raspberrypi kernel: [   17.093930] Bluetooth: BNEP socket layer initialized
Nov 30 23:04:09 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.25' (uid=0 pid=3873 comm="/usr/libexec/bluetooth/bluetoothd ")
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: Bluetooth management interface 1.18 initialized
Nov 30 23:04:09 raspberrypi systemd[1]: Starting Hostname Service...
Nov 30 23:04:09 raspberrypi kernel: [   17.124164] NET: Registered protocol family 38
Nov 30 23:04:09 raspberrypi kernel: [   17.169792] cryptd: max_cpu_qlen set to 1000
Nov 30 23:04:09 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.freedesktop.hostname1'
Nov 30 23:04:09 raspberrypi systemd[1]: Started Hostname Service.
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: sap-server: Operation not permitted (1)
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: Endpoint registered: sender=:1.23 path=/MediaEndpoint/A2DPSink/sbc
Nov 30 23:04:09 raspberrypi bluetoothd[3873]: Endpoint registered: sender=:1.23 path=/MediaEndpoint/A2DPSource/sbc
Nov 30 23:04:09 raspberrypi pulseaudio[2763]: Found duplicated D-Bus path for adapter /org/bluez/hci0
Nov 30 23:04:10 raspberrypi kernel: [   17.362664] Bluetooth: RFCOMM TTY layer initialized
Nov 30 23:04:10 raspberrypi kernel: [   17.362686] Bluetooth: RFCOMM socket layer initialized
Nov 30 23:04:10 raspberrypi kernel: [   17.362709] Bluetooth: RFCOMM ver 1.11
Nov 30 23:04:10 raspberrypi bluetoothd[3873]: Failed to set privacy: Rejected (0x0b)
Nov 30 23:04:10 raspberrypi mopidy[579]: ERROR    [SpotifyBackend-6] mopidy_spotify.web OAuth token refresh failed: Unknown error.
Nov 30 23:04:10 raspberrypi mopidy[579]: ERROR    [SpotifyBackend-6] mopidy_spotify.web Failed to load Spotify user profile
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting Mopidy core
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting Mopidy frontends: IrisFrontend, HttpFrontend, MpdFrontend
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [IrisFrontend-11] mopidy_iris.core Starting Iris 3.54.2
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [HttpFrontend-13] mopidy.http.actor HTTP server running at [::ffff:0.0.0.0]:6680
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MainThread] mopidy_mpd.actor MPD server running at [::ffff:0.0.0.0]:6600
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MainThread] mopidy.commands Starting GLib mainloop
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-15] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55288
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-16] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55292
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-17] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55296
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-18] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55300
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-19] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55304
Nov 30 23:04:10 raspberrypi bash[4358]: OK MPD 0.19.0
Nov 30 23:04:10 raspberrypi bash[4358]: OK
Nov 30 23:04:10 raspberrypi bash[4358]: OK
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-20] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55308
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-21] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55312
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-22] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55316
Nov 30 23:04:10 raspberrypi mopidy[579]: INFO     [MpdSession-23] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55320
Nov 30 23:04:10 raspberrypi bash[4397]: OK MPD 0.19.0
Nov 30 23:04:10 raspberrypi bash[4397]: OK
Nov 30 23:04:10 raspberrypi bash[4397]: OK
Nov 30 23:04:10 raspberrypi bash[434]: 9830 is the mpg123 startup volume
Nov 30 23:04:10 raspberrypi bash[4399]: High Performance MPEG 1.0/2.0/2.5 Audio Player for Layers 1, 2 and 3
Nov 30 23:04:10 raspberrypi bash[4399]: #011version 1.26.4; written and copyright by Michael Hipp and others
Nov 30 23:04:10 raspberrypi bash[4399]: #011free software (LGPL) without any warranty but with best wishes
Nov 30 23:04:10 raspberrypi bash[4399]: Cannot connect to server socket err = No such file or directory
Nov 30 23:04:10 raspberrypi bash[4399]: Cannot connect to server request channel
Nov 30 23:04:10 raspberrypi bash[4399]: jack server is not running or cannot be started
Nov 30 23:04:10 raspberrypi bash[4399]: JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
Nov 30 23:04:10 raspberrypi bash[4399]: JackShmReadWritePtr::~JackShmReadWritePtr - Init not done for -1, skipping unlock
Nov 30 23:04:10 raspberrypi bash[434]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 53:  4399 Segmentation fault      /usr/bin/mpg123 -f -${mpgvolume} /home/pi/RPi-Jukebox-RFID/shared/startupsound.mp3
Nov 30 23:04:11 raspberrypi mopidy[579]: INFO     [MpdSession-24] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55324
Nov 30 23:04:11 raspberrypi bash[4401]: volume: 30%   repeat: off   random: off   single: off   consume: off
Nov 30 23:04:11 raspberrypi systemd[1]: Finished Phoniebox Startup.
Nov 30 23:04:11 raspberrypi dhcpcd[569]: wlan0: probing address 192.168.5.54/24
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: Router Advertisement from fe80::de15:c8ff:feb1:bc2e
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: adding address 2003:ca:cf12:f800:d16f:a34e:166:e68b/64
Nov 30 23:04:12 raspberrypi kernel: [   20.281657] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.wlan0.retrans_time - use net.ipv6.neigh.wlan0.retrans_time_ms instead
Nov 30 23:04:12 raspberrypi avahi-daemon[411]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::a8d9:1388:54e6:bc66.
Nov 30 23:04:12 raspberrypi avahi-daemon[411]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2003:ca:cf12:f800:d16f:a34e:166:e68b.
Nov 30 23:04:12 raspberrypi avahi-daemon[411]: Registering new address record for 2003:ca:cf12:f800:d16f:a34e:166:e68b on wlan0.*.
Nov 30 23:04:12 raspberrypi avahi-daemon[411]: Withdrawing address record for fe80::a8d9:1388:54e6:bc66 on wlan0.
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: adding route to 2003:ca:cf12:f800::/64
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: requesting DHCPv6 information
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: fe80::de15:c8ff:feb1:bc2e is reachable again
Nov 30 23:04:12 raspberrypi dhcpcd[569]: wlan0: adding default route via fe80::de15:c8ff:feb1:bc2e
Nov 30 23:04:13 raspberrypi systemd[1]: Stopping Network Time Synchronization...
Nov 30 23:04:13 raspberrypi systemd[1]: systemd-timesyncd.service: Succeeded.
Nov 30 23:04:13 raspberrypi systemd[1]: Stopped Network Time Synchronization.
Nov 30 23:04:13 raspberrypi systemd[1]: Starting Network Time Synchronization...
Nov 30 23:04:13 raspberrypi systemd[1]: Started Network Time Synchronization.
Nov 30 23:04:14 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Nov 30 23:04:14 raspberrypi bthelper[4444]: Changing power off succeeded
Nov 30 23:04:14 raspberrypi bthelper[4444]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller DC:A6:32:3F:6B:F9 Powered: no
Nov 30 23:04:14 raspberrypi bthelper[4444]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller DC:A6:32:3F:6B:F9 Discovering: no
Nov 30 23:04:14 raspberrypi bthelper[4444]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller DC:A6:32:3F:6B:F9 Class: 0x00000000
Nov 30 23:04:14 raspberrypi bthelper[3871]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller DC:A6:32:3F:6B:F9 Class: 0x002c0000
Nov 30 23:04:14 raspberrypi bthelper[3871]: Changing power on succeeded
Nov 30 23:04:16 raspberrypi dhcpcd[569]: wlan0: leased 192.168.5.54 for 864000 seconds
Nov 30 23:04:16 raspberrypi avahi-daemon[411]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.5.54.
Nov 30 23:04:16 raspberrypi avahi-daemon[411]: New relevant interface wlan0.IPv4 for mDNS.
Nov 30 23:04:16 raspberrypi dhcpcd[569]: wlan0: adding route to 192.168.5.0/24
Nov 30 23:04:16 raspberrypi avahi-daemon[411]: Registering new address record for 192.168.5.54 on wlan0.IPv4.
Nov 30 23:04:16 raspberrypi dhcpcd[569]: wlan0: adding default route via 192.168.5.1
Nov 30 23:04:16 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.8' (uid=1000 pid=2814 comm="/usr/bin/lxsession -s LXDE-pi -e LXDE -w openbox-l")
Nov 30 23:04:16 raspberrypi systemd[2508]: Starting Virtual filesystem service...
Nov 30 23:04:16 raspberrypi systemd[1]: Stopping Network Time Synchronization...
Nov 30 23:04:16 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.Daemon'
Nov 30 23:04:16 raspberrypi systemd[2508]: Started Virtual filesystem service.
Nov 30 23:04:16 raspberrypi systemd[1]: systemd-timesyncd.service: Succeeded.
Nov 30 23:04:16 raspberrypi systemd[1]: Stopped Network Time Synchronization.
Nov 30 23:04:16 raspberrypi systemd[1]: Starting Network Time Synchronization...
Nov 30 23:04:16 raspberrypi systemd[1]: Started Network Time Synchronization.
Nov 30 23:04:32 raspberrypi systemd-timesyncd[4491]: Initial synchronization to time server 193.106.144.7:123 (0.debian.pool.ntp.org).
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service' requested by ':1.13' (uid=1000 pid=4508 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 30 23:04:33 raspberrypi systemd[2508]: Starting Virtual filesystem service - disk device monitor...
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Nov 30 23:04:33 raspberrypi systemd[2508]: Started Virtual filesystem service - disk device monitor.
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.13' (uid=1000 pid=4508 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 30 23:04:33 raspberrypi systemd[2508]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Nov 30 23:04:33 raspberrypi systemd[2508]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.13' (uid=1000 pid=4508 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 30 23:04:33 raspberrypi systemd[2508]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Nov 30 23:04:33 raspberrypi systemd[2508]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by ':1.13' (uid=1000 pid=4508 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 30 23:04:33 raspberrypi systemd[2508]: Starting Virtual filesystem service - digital camera monitor...
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Nov 30 23:04:33 raspberrypi systemd[2508]: Started Virtual filesystem service - digital camera monitor.
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service' requested by ':1.13' (uid=1000 pid=4508 comm="pcmanfm --desktop --profile LXDE-pi ")
Nov 30 23:04:33 raspberrypi systemd[2508]: Starting Virtual filesystem service - Apple File Conduit monitor...
Nov 30 23:04:33 raspberrypi dbus-daemon[2808]: [session uid=1000 pid=2808] Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Nov 30 23:04:33 raspberrypi systemd[2508]: Started Virtual filesystem service - Apple File Conduit monitor.
Nov 30 23:04:33 raspberrypi systemd[1]: Started Samba NMB Daemon.
Nov 30 23:04:33 raspberrypi systemd[1]: Starting Samba SMB Daemon...
Nov 30 23:04:33 raspberrypi dhcpcd[569]: wlan0: fe80::de15:c8ff:feb1:bc2e is reachable again
Nov 30 23:04:33 raspberrypi dhcpcd[569]: wlan0: fe80::de15:c8ff:feb1:bc2e is reachable again
Nov 30 23:04:34 raspberrypi systemd[1]: Started Samba SMB Daemon.
Nov 30 23:04:34 raspberrypi systemd[1]: Reached target Multi-User System.
Nov 30 23:04:34 raspberrypi systemd[1]: Reached target Graphical Interface.
Nov 30 23:04:34 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Nov 30 23:04:34 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Nov 30 23:04:34 raspberrypi systemd[1]: Finished Update UTMP about System Runlevel Changes.
Nov 30 23:04:34 raspberrypi systemd[1]: Startup finished in 1.976s (kernel) + 24.256s (userspace) = 26.233s.
Nov 30 23:04:34 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.39' (uid=1000 pid=4506 comm="lxpanel --profile LXDE-pi ")
Nov 30 23:04:34 raspberrypi systemd[1]: Starting PackageKit Daemon...
Nov 30 23:04:34 raspberrypi PackageKit: daemon start
Nov 30 23:04:35 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Nov 30 23:04:35 raspberrypi systemd[1]: Started PackageKit Daemon.
Nov 30 23:04:35 raspberrypi dbus-daemon[414]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service' requested by ':1.8' (uid=0 pid=551 comm="/usr/sbin/cupsd -l ")
Nov 30 23:04:35 raspberrypi systemd[1]: Starting Manage, Install and Generate Color Profiles...
Nov 30 23:04:35 raspberrypi dbus-daemon[414]: [system] Successfully activated service 'org.freedesktop.ColorManager'
Nov 30 23:04:35 raspberrypi systemd[1]: Started Manage, Install and Generate Color Profiles.
Nov 30 23:04:38 raspberrypi PackageKit: refresh-cache transaction /140_cdececdd from uid 1000 finished with success after 2929ms
Nov 30 23:04:38 raspberrypi mopidy[579]: INFO     [MpdSession-25] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55338
Nov 30 23:04:38 raspberrypi mopidy[579]: INFO     [MpdSession-26] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55342
Nov 30 23:04:39 raspberrypi systemd[1]: Started Session 4 of user pi.
Nov 30 23:04:43 raspberrypi PackageKit: get-updates transaction /141_ccdcadba from uid 1000 finished with success after 4993ms
Nov 30 23:04:43 raspberrypi mopidy[579]: INFO     [MpdSession-27] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55372
Nov 30 23:04:44 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Nov 30 23:04:49 raspberrypi mopidy[579]: INFO     [MpdSession-28] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55382
Nov 30 23:04:53 raspberrypi mopidy[579]: INFO     [SpotifyBackend-6] mopidy_spotify.lookup Failed to lookup 'spotify:album:5awrJZBt3rP9RO5hlYdZB0': Session must be logged in and online to load objects: <ConnectionState.LOGGED_OUT: 0>
Nov 30 23:04:53 raspberrypi dhcpcd[569]: wlan0: Router Advertisement from fe80::de15:c8ff:feb1:bc2e
Nov 30 23:04:54 raspberrypi mopidy[579]: INFO     [MpdSession-29] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55384
Nov 30 23:04:54 raspberrypi systemd[1]: Stopping Network Time Synchronization...
Nov 30 23:04:54 raspberrypi systemd[1]: systemd-timesyncd.service: Succeeded.
Nov 30 23:04:54 raspberrypi systemd[1]: Stopped Network Time Synchronization.
Nov 30 23:04:54 raspberrypi systemd[1]: Starting Network Time Synchronization...
Nov 30 23:04:54 raspberrypi systemd[1]: Started Network Time Synchronization.
Nov 30 23:04:54 raspberrypi systemd-timesyncd[5048]: Initial synchronization to time server 193.106.144.7:123 (0.debian.pool.ntp.org).
Nov 30 23:04:55 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Nov 30 23:04:57 raspberrypi dhcpcd[569]: wlan0: Router Advertisement from fe80::de15:c8ff:feb1:bc2e
Nov 30 23:04:58 raspberrypi systemd[1]: Stopping Network Time Synchronization...
Nov 30 23:04:58 raspberrypi systemd[1]: systemd-timesyncd.service: Succeeded.
Nov 30 23:04:58 raspberrypi systemd[1]: Stopped Network Time Synchronization.
Nov 30 23:04:58 raspberrypi systemd[1]: Starting Network Time Synchronization...
Nov 30 23:04:58 raspberrypi systemd[1]: Started Network Time Synchronization.
Nov 30 23:04:58 raspberrypi systemd-timesyncd[5085]: Initial synchronization to time server 193.106.144.7:123 (0.debian.pool.ntp.org).
Nov 30 23:04:59 raspberrypi mopidy[579]: INFO     [MpdSession-30] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55386
Nov 30 23:05:04 raspberrypi mopidy[579]: INFO     [MpdSession-31] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55388
Nov 30 23:05:10 raspberrypi mopidy[579]: INFO     [MpdSession-32] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55390
Nov 30 23:05:16 raspberrypi mopidy[579]: INFO     [MpdSession-33] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55392
Nov 30 23:05:17 raspberrypi systemd[1]: phoniebox-idle-watchdog.service: Succeeded.
Nov 30 23:05:22 raspberrypi mopidy[579]: INFO     [MpdSession-34] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55394
Nov 30 23:05:27 raspberrypi mopidy[579]: INFO     [MpdSession-35] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55396
Nov 30 23:05:33 raspberrypi mopidy[579]: INFO     [MpdSession-36] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55398
Nov 30 23:05:38 raspberrypi mopidy[579]: INFO     [MpdSession-37] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55400
Nov 30 23:05:46 raspberrypi mopidy[579]: INFO     [MpdSession-38] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55402
Nov 30 23:05:51 raspberrypi mopidy[579]: INFO     [MpdSession-39] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55404
Nov 30 23:05:56 raspberrypi mopidy[579]: INFO     [MpdSession-40] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55406
Nov 30 23:06:01 raspberrypi mopidy[579]: INFO     [MpdSession-41] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55408
Nov 30 23:06:06 raspberrypi mopidy[579]: INFO     [MpdSession-42] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55410
Nov 30 23:06:11 raspberrypi mopidy[579]: INFO     [MpdSession-43] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55412
Nov 30 23:06:16 raspberrypi mopidy[579]: INFO     [MpdSession-44] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55414
Nov 30 23:06:21 raspberrypi mopidy[579]: INFO     [MpdSession-45] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55416
Nov 30 23:06:26 raspberrypi mopidy[579]: INFO     [MpdSession-46] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55418
Nov 30 23:06:32 raspberrypi mopidy[579]: INFO     [MpdSession-47] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:55420
I think the most important line is: Nov 30 23:04:10 raspberrypi bash[434]: /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh: line 53: 4399 Segmentation fault /usr/bin/mpg123 -f -${mpgvolume} /home/pi/RPi-Jukebox-RFID/shared/startupsound.mp3
--> does anyone know what the reason for this could be?
when i try: /usr/bin/mpg123 /home/pi/RPi-Jukebox-RFID/shared/startupsound.mp3 --> the box does play the sound.
my gpio settings: [DEFAULT] enabled : False type : Button pin : 3 hold_time : 2 functioncall : functionCallShutdown pull_up_down : pull_up [Volume0] enabled : False type : Button pin : 17 hold_time : 0.3 functioncall : functionCallVol0 pull_up_down : pull_up [VolumeUp] enabled : True type : Button pin : 7 hold_time : 0.3 functioncall : functionCallVolU pull_up_down : pull_up hold_mode : Repeat [VolumeDown] enabled : True type : Button pin : 13 hold_time : 0.3 functioncall : functionCallVolD pull_up_down : pull_up hold_mode : Repeat [NextSong] enabled : True type : Button pin : 8 hold_time : 0.3 functioncall : functionCallPlayerNext pull_up_down : pull_up [PrevSong] enabled : True type : Button pin : 27 hold_time : 0.3 functioncall : functionCallPlayerPrev pull_up_down : pull_up [Halt] enabled : False type : Button pin : 21 hold_time : 0.3 functioncall : functionCallPlayerPauseForce pull_up_down : pull_up
startupVolume is also set to 30 over the website
my configuration for sudo nano etc/systemd/system/phoniebox-startup-scripts.service
[Unit] Description=Phoniebox Startup After=mpd.service
[Service] User=pi Group=pi Type=oneshot RemainAfterExit=true WorkingDirectory=/home/pi/RPi-Jukebox-RFID ExecStart=/bin/bash /home/pi/RPi-Jukebox-RFID/scripts/startup-scripts.sh
MiczFlor / RPi-Jukebox-RFID
