Apr 12 14:48:10 pi5dev sudo[6015]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Apr 12 14:48:10 pi5dev sudo[6015]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Apr 12 14:48:16 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:48:16 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 16 Apr 12 14:48:16 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:48:16 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Apr 12 14:48:16 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:16 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:16 pi5dev bluealsa[1126]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Apr 12 14:48:16 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:16 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:16 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:48:16 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:16 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:16 pi5dev volumio[4538]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 14:48:16 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [5183] D: aplay.c:643: BT device marked as inactive: 5C:17:CF:0D:C0:70 Apr 12 14:48:26 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Received new metadata for 5C:17:CF:0D:C0:70 Apr 12 14:48:26 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-5C:17:CF:0D:C0:70.json Apr 12 14:48:26 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:26 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:26 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:26 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:26 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:26 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Received new metadata for 5C:17:CF:0D:C0:70 Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-5C:17:CF:0D:C0:70.json Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:27 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/ba-transport.c:319: New A2DP transport: 15 Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 5C:17:CF:0D:C0:70 Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Playback started, enabling output Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:672 W:1008 Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:27 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 16 Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:27 pi5dev volumio[4538]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 12 14:48:27 pi5dev bluealsa[1126]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [5183] D: aplay.c:732: Opening ALSA playback PCM: name=volumio channels=2 rate=44100 Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:27 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:27 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:27 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [5183] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Apr 12 14:48:27 pi5dev volumio[4538]: bluealsa-aplay: [5183] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Apr 12 14:48:27 pi5dev volumio[4538]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Apr 12 14:48:27 pi5dev volumio[4538]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Apr 12 14:48:27 pi5dev volumio[4538]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Apr 12 14:48:27 pi5dev volumio[4538]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Apr 12 14:48:27 pi5dev volumio[4538]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Apr 12 14:48:27 pi5dev volumio[4538]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Apr 12 14:48:27 pi5dev volumio[4538]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Apr 12 14:48:27 pi5dev volumio[4538]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 12 14:48:27 pi5dev volumio[4538]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 14:48:27 pi5dev volumio[4538]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Apr 12 14:48:27 pi5dev volumio[4538]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Apr 12 14:48:27 pi5dev volumio[4538]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Apr 12 14:48:27 pi5dev volumio[4538]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Apr 12 14:48:27 pi5dev volumio[4538]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Apr 12 14:48:27 pi5dev volumio[4538]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Apr 12 14:48:27 pi5dev volumio[4538]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Apr 12 14:48:27 pi5dev volumio[4538]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 12 14:48:27 pi5dev volumio[4538]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 14:48:29 pi5dev volumio[4538]: info: Executing endpoint metavolumio Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:48:29 pi5dev volumio[4538]: info: Executing endpoint metavolumio Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:48:29 pi5dev volumio[4538]: info: Executing endpoint metavolumio Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:48:29 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:48:29 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:48:29 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::servicePushState Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreStateMachine::pushState Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:29 pi5dev volumio[4538]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:29 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 16 Apr 12 14:48:29 pi5dev bluealsa[1126]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Apr 12 14:48:29 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:48:29 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:29 pi5dev volumio[4538]: info: MRS: Pushing multiroomSync output Apr 12 14:48:29 pi5dev volumio[4538]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 14:48:29 pi5dev volumio[4538]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [5183] D: aplay.c:643: BT device marked as inactive: 5C:17:CF:0D:C0:70 Apr 12 14:48:40 pi5dev sudo[6072]: volumio : TTY=pts/2 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl restart volumio Apr 12 14:48:40 pi5dev sudo[6072]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Apr 12 14:48:40 pi5dev systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 12 14:48:40 pi5dev systemd[1]: Stopping volumio.service - Volumio Backend Module... Apr 12 14:48:40 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:453: Closing PCM: 18 Apr 12 14:48:40 pi5dev bluealsa[1126]: ../src/ba-transport.c:203: PCM clients check keep-alive: 0 ms Apr 12 14:48:40 pi5dev systemd[1]: dynamicswap.service: Deactivated successfully. Apr 12 14:48:40 pi5dev vtcs[5012]: [2025-04-12 14:48:40.301] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Apr 12 14:48:40 pi5dev volumio-remote-updater[996]: [2025-04-12 14:48:40] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 12 14:48:40 pi5dev volumio-remote-updater[996]: [2025-04-12 14:48:40] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 12 14:48:40 pi5dev systemd[1]: volumio.service: Deactivated successfully. Apr 12 14:48:40 pi5dev systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 12 14:48:40 pi5dev systemd[1]: volumio.service: Consumed 14.377s CPU time. Apr 12 14:48:40 pi5dev systemd[1]: Started volumio.service - Volumio Backend Module. Apr 12 14:48:40 pi5dev sudo[6072]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:40 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:40 pi5dev volumio[6103]: info: ----- Volumio3 ---- Apr 12 14:48:40 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:40 pi5dev volumio[6103]: info: ----- System startup ---- Apr 12 14:48:40 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:40 pi5dev volumio[6103]: info: MYVOLUMIO Environment detected Apr 12 14:48:40 pi5dev volumio[6103]: info: Plugin folders cleanup Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning into folder /volumio/app/plugins/ Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category audio_interface Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category miscellanea Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category music_service Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category plugins.json Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category system_controller Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category user_interface Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning into folder /data/plugins/ Apr 12 14:48:40 pi5dev volumio[6103]: info: Scanning category user_interface Apr 12 14:48:40 pi5dev volumio[6103]: info: Plugin folders cleanup completed Apr 12 14:48:40 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:40 pi5dev volumio[6103]: info: ----- Core plugins startup ---- Apr 12 14:48:40 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:40 pi5dev volumio[6103]: info: Loading plugins from folder /volumio/app/plugins/ Apr 12 14:48:40 pi5dev volumio[6103]: info: Adding plugin upnp to MyMusic Plugins Apr 12 14:48:40 pi5dev volumio[6103]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 12 14:48:40 pi5dev volumio[6103]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 12 14:48:40 pi5dev volumio[6103]: info: Loading plugins from folder /data/plugins/ Apr 12 14:48:40 pi5dev volumio[6103]: info: Loading plugin "system"... Apr 12 14:48:40 pi5dev volumio[6103]: info: Loading plugin "appearance"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "network"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Refreshing Cached IP Addresses Apr 12 14:48:41 pi5dev sudo[6126]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 14:48:41 pi5dev sudo[6126]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev sudo[6126]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:41 pi5dev sudo[6128]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 14:48:41 pi5dev sudo[6128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev sudo[6128]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "services"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "alsa_controller"... Apr 12 14:48:41 pi5dev sudo[6137]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 12 14:48:41 pi5dev sudo[6137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "wizard"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "networkfs"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Starting Udev Watcher for removable devices Apr 12 14:48:41 pi5dev volumio[6103]: info: Ignoring mount for partition: boot Apr 12 14:48:41 pi5dev volumio[6103]: info: Ignoring mount for partition: volumio Apr 12 14:48:41 pi5dev volumio[6103]: info: Ignoring mount for partition: volumio_data Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "volumio_command_line_client"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "upnp"... Apr 12 14:48:41 pi5dev volumio[6103]: info: [1744465721138] Starting Upmpd Daemon Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "my_music"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "mpd"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "upnp_browser"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "alarm-clock"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "airplay_emulation"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Starting Shairport Sync Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "last_100"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "webradio"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "i2s_dacs"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "volumiodiscovery"... Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** For more information see Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 14:48:41 pi5dev volumio[6103]: *** WARNING *** For more information see Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** For more information see Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 12 14:48:41 pi5dev node[6103]: *** WARNING *** For more information see Apr 12 14:48:41 pi5dev volumio[6103]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 12 14:48:41 pi5dev volumio[6103]: info: Discovery: Started advertising with name: pi5dev Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "outputs"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "albumart"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Plugin example_plugin is not enabled Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "inputs"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "updater_comm"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Plugin mpdemulation is not enabled Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "rest_api"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "websocket"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Starting Socket.io Server version 1.7.4 Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading plugin "touch_display"... Apr 12 14:48:41 pi5dev volumio[6103]: info: Applying required configuration parameters for plugin touch_display Apr 12 14:48:41 pi5dev volumio[6158]: Forking 3 albumart workers Apr 12 14:48:41 pi5dev volumio[6103]: info: Loading i18n strings for locale en Apr 12 14:48:41 pi5dev volumio[6103]: Updating browse sources language Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::initPlayerControls Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: Express server listening on port 3000 Apr 12 14:48:41 pi5dev volumio[6103]: [Metrics] WebUI: 1s 93.71ms Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::resetVolumioState Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::getcurrentVolume Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 14:48:41 pi5dev volumio[6103]: info: Cannot read play queue from file Apr 12 14:48:41 pi5dev volumio[6103]: info: Volumio Network Manager: Network status updated: 1 Apr 12 14:48:41 pi5dev volumio[6103]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::updateTrackBlock Apr 12 14:48:41 pi5dev volumio[6103]: info: CorePlayQueue::getTrackBlock Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 14:48:41 pi5dev volumio[6103]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::setRepeat undefined single undefined Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::setRandom true Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:41 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:41 pi5dev volumio[6103]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 12 14:48:41 pi5dev volumio[6103]: info: USB Boot Capable - System SBC Revision found in cpuinfo: e04171 Apr 12 14:48:41 pi5dev volumio[6103]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 12 14:48:41 pi5dev volumio[6103]: info: Setting Device type: Raspberry PI Apr 12 14:48:41 pi5dev volumio[6103]: info: Completed loading Core Plugins Apr 12 14:48:41 pi5dev volumio[6103]: info: Preparing to generate the ALSA configuration file Apr 12 14:48:41 pi5dev volumio[6103]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 12 14:48:41 pi5dev volumio[6103]: info: Reading ALSA contributions from plugins. Apr 12 14:48:41 pi5dev volumio[6103]: info: Asound.conf file written Apr 12 14:48:41 pi5dev sudo[6222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 12 14:48:41 pi5dev sudo[6222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev sudo[6222]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:41 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 12 14:48:41 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 12 14:48:41 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 12 14:48:41 pi5dev volumio[6103]: info: Output device has changed, restarting MPD Apr 12 14:48:41 pi5dev volumio[6103]: info: Output device has changed, restarting Shairport Sync Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:41 pi5dev sudo[6228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 14:48:41 pi5dev sudo[6228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev sudo[6228]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:41 pi5dev sudo[6230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 14:48:41 pi5dev sudo[6230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev volumio[6103]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 14:48:41 pi5dev volumio[6103]: info: ___________ START PLUGINS ___________ Apr 12 14:48:41 pi5dev volumio[6103]: info: ControllerMpd::onStart: Initializing MPD Apr 12 14:48:41 pi5dev volumio[6103]: info: Creating MPD Configuration file Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 14:48:41 pi5dev volumio[6103]: info: [1744465721923] CoreMusicLibrary::Adding element Media Servers Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 14:48:41 pi5dev sudo[6239]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 14:48:41 pi5dev sudo[6239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:41 pi5dev systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 12 14:48:41 pi5dev sudo[6241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 14:48:41 pi5dev sudo[6241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:41 pi5dev sudo[6239]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:41 pi5dev volumio[6103]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 14:48:41 pi5dev volumio[6103]: info: [1744465721958] CoreMusicLibrary::Adding element Last_100 Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 14:48:41 pi5dev volumio[6103]: info: [1744465721959] CoreMusicLibrary::Adding element Webradio Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 14:48:41 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:48:41 pi5dev volumio[6103]: info: Initializing BBC Radios Apr 12 14:48:41 pi5dev systemd[1]: mpd.service: Deactivated successfully. Apr 12 14:48:41 pi5dev systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 12 14:48:41 pi5dev systemd[1]: mpd.socket: Deactivated successfully. Apr 12 14:48:41 pi5dev systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 12 14:48:41 pi5dev systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 12 14:48:41 pi5dev volumio[6169]: Starting albumart workers Apr 12 14:48:42 pi5dev systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:42 pi5dev systemd[1]: Starting mpd.service - Music Player Daemon... Apr 12 14:48:42 pi5dev volumio[6103]: info: Loading i18n strings for locale en Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:48:42 pi5dev volumio[6103]: info: Volumio Calling Home Apr 12 14:48:42 pi5dev volumio[6168]: Starting albumart workers Apr 12 14:48:42 pi5dev sudo[6274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 12 14:48:42 pi5dev sudo[6274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 12 14:48:42 pi5dev sudo[6277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 12 14:48:42 pi5dev systemd[1]: Reloading. Apr 12 14:48:42 pi5dev sudo[6273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6268]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 14:48:42 pi5dev sudo[6268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 14:48:42 pi5dev sudo[6268]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:42 pi5dev volumio[6170]: Starting albumart workers Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: Backlight interface detected. Apr 12 14:48:42 pi5dev volumio[6103]: info: MPD Permissions set Apr 12 14:48:42 pi5dev volumio[6103]: info: MPD Permissions set Apr 12 14:48:42 pi5dev volumio[6103]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 12 14:48:42 pi5dev volumio[6103]: info: Volumio called home Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:42 pi5dev volumio[6103]: info: Starting Shairport Sync Apr 12 14:48:42 pi5dev sudo[6321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 14:48:42 pi5dev sudo[6321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: Raspberry Pi Foundation touch screen detected. Apr 12 14:48:42 pi5dev volumio[6103]: info: Starting Shairport Sync Apr 12 14:48:42 pi5dev sudo[6326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 12 14:48:42 pi5dev sudo[6326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Apr 12 14:48:42 pi5dev sudo[6324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/11-0045/brightness Apr 12 14:48:42 pi5dev sudo[6324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev volumio[6103]: info: Starting Shairport Sync Apr 12 14:48:42 pi5dev sudo[6329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6324]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:42 pi5dev sudo[6326]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: File permissions for backlight brightness control set. Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 12 14:48:42 pi5dev sudo[6333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 14:48:42 pi5dev sudo[6333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev sudo[6329]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Apr 12 14:48:42 pi5dev sudo[6341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 14:48:42 pi5dev sudo[6341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev sudo[6277]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:42 pi5dev volumio[6103]: info: touch_display: systemctl daemon-reload succeeded. Apr 12 14:48:42 pi5dev sudo[6348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 12 14:48:42 pi5dev sudo[6348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:42 pi5dev systemd[1]: Reloading. Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/volumio-remote-updater.service:5: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/volumio-remote-updater.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: adding de3fdaf1-89d9-4ed3-bb96-ff6c4f4ef275 Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: Found device pi5dev Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:42 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: this is already registered, de3fdaf1-89d9-4ed3-bb96-ff6c4f4ef275 Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: Found device pi5dev Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:42 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: this is already registered, de3fdaf1-89d9-4ed3-bb96-ff6c4f4ef275 Apr 12 14:48:42 pi5dev volumio[6103]: info: Discovery: Found device pi5dev Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:42 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:42 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:42 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:42 pi5dev mpd[6346]: Apr 12 14:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:42 pi5dev systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 12 14:48:43 pi5dev systemd[1]: Started mpd.service - Music Player Daemon. Apr 12 14:48:43 pi5dev sudo[6274]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev sudo[6241]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev sudo[6230]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 12 14:48:43 pi5dev systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 12 14:48:43 pi5dev sudo[6348]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev systemd[1]: shairport-sync.service: Deactivated successfully. Apr 12 14:48:43 pi5dev systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 14:48:43 pi5dev systemd[1]: shairport-sync.service: Consumed 2.189s CPU time. Apr 12 14:48:43 pi5dev volumio[6103]: error: MPD error: The expression evaluated to a falsy value: Apr 12 14:48:43 pi5dev volumio[6103]: assert.ok(self.idling) Apr 12 14:48:43 pi5dev volumio[6103]: error: The expression evaluated to a falsy value: Apr 12 14:48:43 pi5dev volumio[6103]: assert.ok(self.idling) Apr 12 14:48:43 pi5dev sudo[6273]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev volumio[6103]: error: updateQueue error: null Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: Volumio Kiosk started. Apr 12 14:48:43 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:43 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:43 pi5dev volumio[6103]: info: Completed starting Core Plugins Apr 12 14:48:43 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:43 pi5dev volumio[6103]: info: ----- MyVolumio plugins startup ---- Apr 12 14:48:43 pi5dev volumio[6103]: info: ------------------------------------------- Apr 12 14:48:43 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 12 14:48:43 pi5dev volumio[6103]: info: MPD running with PID6346 Apr 12 14:48:43 pi5dev volumio[6103]: ,establishing connection Apr 12 14:48:43 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:43 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 12 14:48:43 pi5dev volumio[6103]: error: updateQueue error: null Apr 12 14:48:43 pi5dev systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 14:48:43 pi5dev sudo[6321]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev volumio[6103]: info: Shairport-Sync Started Apr 12 14:48:43 pi5dev sudo[6333]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev sudo[6341]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:43 pi5dev volumio[6103]: Error adding Membership: Error: addMembership EINVAL Apr 12 14:48:43 pi5dev volumio[6103]: info: Shairport-Sync Started Apr 12 14:48:43 pi5dev volumio[6103]: info: Shairport-Sync Started Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: X display number found: 0 Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 12 14:48:43 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:43 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: X display number found: 0 Apr 12 14:48:43 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 14:48:44 pi5dev volumio[6103]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetVisibleSources Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:44 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:44 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 12 14:48:44 pi5dev volumio[6103]: info: Received Get System Info Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 14:48:44 pi5dev volumio[6103]: info: Discovery: Getting this device information Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:44 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 14:48:44 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:44 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:44 pi5dev volumio[6103]: info: Listing playlists Apr 12 14:48:45 pi5dev sudo[6137]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:45 pi5dev volumio-remote-updater[996]: [2025-04-12 14:48:45] [connect] Successful connection Apr 12 14:48:45 pi5dev volumio[6103]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5 Apr 12 14:48:45 pi5dev volumio-remote-updater[996]: [2025-04-12 14:48:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744465725 101 Apr 12 14:48:48 pi5dev volumio[6103]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 12 14:48:51 pi5dev sudo[6415]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 14:48:51 pi5dev sudo[6415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:51 pi5dev sudo[6417]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 14:48:51 pi5dev sudo[6417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:51 pi5dev sudo[6415]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:51 pi5dev sudo[6417]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:51 pi5dev sudo[6419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 14:48:51 pi5dev sudo[6419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:51 pi5dev sudo[6419]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:51 pi5dev volumio[6103]: info: Upmpdcli Daemon Started Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin bluetooth to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin multiroom to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin metavolumio to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin cd_controller to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 12 14:48:51 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 12 14:48:52 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:52 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:52 pi5dev volumio[6103]: info: Starting MyVolumio Remote Streaming Endpoints Apr 12 14:48:52 pi5dev volumio[6103]: info: MyVolumio login type: Token Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 12 14:48:52 pi5dev volumio[6103]: info: Streaming services startup Apr 12 14:48:52 pi5dev volumio[6103]: info: Starting Streaming Daemon Apr 12 14:48:52 pi5dev sudo[6424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 14:48:52 pi5dev sudo[6424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:52 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 12 14:48:52 pi5dev sudo[6424]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:52 pi5dev volumio[6103]: error: Cannot start Volumio Streaming Daemon Apr 12 14:48:52 pi5dev volumio[6103]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 14:48:52 pi5dev volumio[6103]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 14:48:52 pi5dev volumio[6103]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 12 14:48:53 pi5dev volumio[6103]: info: MyVolumio token set successfully Apr 12 14:48:53 pi5dev volumio[6103]: info: MYVOLUMIO: Adding device Apr 12 14:48:53 pi5dev volumio[6103]: info: MYVOLUMIO: Evaluating Server Apr 12 14:48:53 pi5dev volumio[6103]: info: MyVolumio Plan changed: premium Apr 12 14:48:53 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 12 14:48:53 pi5dev volumio[6103]: info: Removing browser output: myVolumio user plan is not superstar Apr 12 14:48:53 pi5dev volumio[6103]: info: Removing audio output: Apr 12 14:48:53 pi5dev volumio[6103]: info: MYVOLUMIO: Adding device Apr 12 14:48:53 pi5dev volumio[6103]: info: MYVOLUMIO: Evaluating Server Apr 12 14:48:53 pi5dev volumio[6103]: info: Remote config written successfully Apr 12 14:48:53 pi5dev volumio[6103]: info: Starting Tunnel 1 Apr 12 14:48:53 pi5dev volumio[6103]: info: Starting Tunnel Connection Checker Apr 12 14:48:53 pi5dev volumio[6103]: info: Completed starting MyVolumio Plugin Apr 12 14:48:54 pi5dev volumio[6103]: info: MYVolumio Device enabled Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 12 14:48:54 pi5dev volumio[6103]: info: MyVolumio status changed Apr 12 14:48:54 pi5dev volumio[6103]: info: Streaming services startup Apr 12 14:48:54 pi5dev volumio[6103]: info: Starting Streaming Daemon Apr 12 14:48:54 pi5dev sudo[6463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 12 14:48:54 pi5dev sudo[6463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 12 14:48:54 pi5dev sudo[6463]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: warn: [MyVolumio PluginManager] It looks like we're trying to load a cleartext plugin in: /myvolumio/plugins/audio_interface/bluetooth/index.js Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 12 14:48:54 pi5dev volumio[6103]: error: [MyVolumio PluginManager] ATTENTION!!!: Plugin bluetooth does not return adequate promise from onVolumioStart: please update! Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Apr 12 14:48:54 pi5dev sudo[6467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 12 14:48:54 pi5dev sudo[6467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev sudo[6467]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: MultiRoom plugin initialized Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: STOPPING SNAPCLIENT Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Snap server stop Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: STOPPING volumioStreaming Apr 12 14:48:54 pi5dev sudo[6484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 12 14:48:54 pi5dev sudo[6484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 12 14:48:54 pi5dev sudo[6486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 12 14:48:54 pi5dev sudo[6486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev sudo[6489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 12 14:48:54 pi5dev sudo[6489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 12 14:48:54 pi5dev sudo[6491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 12 14:48:54 pi5dev sudo[6491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 12 14:48:54 pi5dev sudo[6491]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 12 14:48:54 pi5dev sudo[6486]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev sudo[6489]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 12 14:48:54 pi5dev sudo[6484]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 12 14:48:54 pi5dev volumio[6103]: info: Preparing to generate the ALSA configuration file Apr 12 14:48:54 pi5dev volumio[6103]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 12 14:48:54 pi5dev volumio[6103]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 12 14:48:54 pi5dev volumio[6103]: info: Reading ALSA contributions from plugins. Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Removed streaming files Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: volumioStreaming STOPPED Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: SNAPSERVER STOPPED Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: SNAPCLIENT STOPPED Apr 12 14:48:54 pi5dev volumio[6103]: error: Cannot start Volumio Streaming Daemon Apr 12 14:48:54 pi5dev volumio[6103]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 12 14:48:54 pi5dev volumio[6103]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 12 14:48:54 pi5dev volumio[6103]: info: Asound.conf file written Apr 12 14:48:54 pi5dev sudo[6497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 12 14:48:54 pi5dev sudo[6497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev sudo[6497]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Apr 12 14:48:54 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Apr 12 14:48:54 pi5dev volumio[6103]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Apr 12 14:48:54 pi5dev volumio[6103]: info: Output device has changed, restarting MPD Apr 12 14:48:54 pi5dev volumio[6103]: info: Output device has changed, restarting Shairport Sync Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev sudo[6505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 14:48:54 pi5dev sudo[6505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev sudo[6503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 14:48:54 pi5dev sudo[6503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev sudo[6503]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 12 14:48:54 pi5dev systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output for this device Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev systemd[1]: mpd.service: Deactivated successfully. Apr 12 14:48:54 pi5dev systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev systemd[1]: mpd.socket: Deactivated successfully. Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding METAVOLUMIO REST API Endpoints Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 12 14:48:54 pi5dev volumio[6103]: info: Preparing CD Folders Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding CD REST API Endpoints Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 12 14:48:54 pi5dev volumio[6103]: info: Starting UDEV Watcher for CD Apr 12 14:48:54 pi5dev volumio[6103]: info: Detecting CD presence with UDEV Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 12 14:48:54 pi5dev bluetoothd[973]: Path / reserved for Adv Monitor app :1.90 Apr 12 14:48:54 pi5dev systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 12 14:48:54 pi5dev systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 12 14:48:54 pi5dev bluetoothd[973]: Adv Monitor app :1.90 disconnected from D-Bus Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding inputs REST Endpoints Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 12 14:48:54 pi5dev volumio[6103]: info: Scanning Audio Inputs Apr 12 14:48:54 pi5dev volumio[6103]: info: Checking against Known Cards name Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding Server instance for streaming Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 12 14:48:54 pi5dev volumio[6103]: error: Hi Res Audio Failed Login: Missing Login Data Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 12 14:48:54 pi5dev volumio[6103]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 12 14:48:54 pi5dev volumio[6103]: info: Stopping AccessToken refresher cron Apr 12 14:48:54 pi5dev sudo[6524]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 12 14:48:54 pi5dev sudo[6524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 12 14:48:54 pi5dev systemd[1]: Starting mpd.service - Music Player Daemon... Apr 12 14:48:54 pi5dev volumio[6103]: info: AccessToken refresher cron started Apr 12 14:48:54 pi5dev volumio[6103]: info: Stopping AccessToken refresher cron for QOBUZ Apr 12 14:48:54 pi5dev volumio[6103]: info: AccessToken refresher cron started for QOBUZ Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding TIDAL REST API Endpoints Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding QOBUZ REST API Endpoints Apr 12 14:48:54 pi5dev systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 12 14:48:54 pi5dev systemd[1]: vtcs.service: Deactivated successfully. Apr 12 14:48:54 pi5dev systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Apr 12 14:48:54 pi5dev volumio[6103]: info: MPD Permissions set Apr 12 14:48:54 pi5dev sudo[6524]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev sudo[6529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 12 14:48:54 pi5dev sudo[6529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev sudo[6529]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:48:54 pi5dev sudo[6527]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 14:48:54 pi5dev sudo[6527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 14:48:54 pi5dev sudo[6527]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [_watchMediaPlayer] Binding activePlayer for path: /org/bluez/hci0/dev_5C_17_CF_0D_C0_70/player0 Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: activePlayer bound: /org/bluez/hci0/dev_5C_17_CF_0D_C0_70/player0 Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::volumioStop Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreStateMachine::stop Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 14:48:54 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 12 14:48:54 pi5dev volumio[6103]: info: Starting Shairport Sync Apr 12 14:48:54 pi5dev sudo[6543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Found cast device: Chromecast-5702c0fa26409e4dc282cbccce3735c4 Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Found cast device: Chromecast-Ultra-bb5475a65116e0c6bfcdcd498eee7139 Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev sudo[6543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Found cast device: Chromecast-Ultra-b8d5e9e179c52d9e75eab34ae52a3903 Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev volumio[6103]: info: MRS: Found cast device: Google-Nest-Hub-da739cebc7bb692ba8bab67636d07159 Apr 12 14:48:54 pi5dev volumio[6103]: info: Adding audio output: Apr 12 14:48:54 pi5dev systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 12 14:48:54 pi5dev systemd[1]: shairport-sync.service: Deactivated successfully. Apr 12 14:48:54 pi5dev systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 14:48:54 pi5dev systemd[1]: shairport-sync.service: Consumed 1.530s CPU time. Apr 12 14:48:54 pi5dev systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 14:48:54 pi5dev sudo[6543]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:54 pi5dev volumio[6103]: info: Setting Geolocation for MyVolumio to eu3 Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: Setting Geolocation for MyVolumio to eu3 Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:54 pi5dev volumio[6103]: info: Shairport-Sync Started Apr 12 14:48:54 pi5dev volumio[6103]: info: Successfully Added MyVolumio device Apr 12 14:48:54 pi5dev volumio[6103]: info: Successfully Added MyVolumio device Apr 12 14:48:55 pi5dev mpd[6540]: Apr 12 14:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 14:48:55 pi5dev systemd[1]: Started mpd.service - Music Player Daemon. Apr 12 14:48:55 pi5dev sudo[6505]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:55 pi5dev volumio[6103]: error: updateQueue error: null Apr 12 14:48:55 pi5dev volumio[6103]: info: Updating MyVolumio device info Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: Updating MyVolumio device info Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:48:55 pi5dev volumio[6103]: info: Successfully Updated MyVolumio device Apr 12 14:48:55 pi5dev volumio[6103]: info: Successfully Updated MyVolumio device Apr 12 14:48:57 pi5dev volumio[6103]: info: TidalConnect service stoped! Apr 12 14:48:57 pi5dev volumio[6103]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 12 14:48:57 pi5dev volumio[6103]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 12 14:48:57 pi5dev sudo[6572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 12 14:48:57 pi5dev sudo[6572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:57 pi5dev systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 12 14:48:57 pi5dev sudo[6572]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:57 pi5dev volumio[6103]: info: Executing endpoint tc_getconfig Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 12 14:48:57 pi5dev vtcs[6575]: STARTING TidalConnect services, version: 1.5.0.45 Apr 12 14:48:57 pi5dev vtcs[6575]: STARTED TidalConnect services. Apr 12 14:48:57 pi5dev volumio[6103]: info: Executing endpoint tc_connect Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 12 14:48:57 pi5dev volumio[6103]: info: Connecting to TidalConnect Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:57 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:57 pi5dev volumio[6103]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 12 14:48:57 pi5dev volumio[6103]: verbose: CURRENT POSITION 0 Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::syncState stateService stop Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::syncState currentStatus stop Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:57 pi5dev volumio[6103]: info: No code Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:57 pi5dev volumio[6103]: info: CorePlayQueue::getTrack 0 Apr 12 14:48:57 pi5dev volumio[6103]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 12 14:48:57 pi5dev volumio[6103]: verbose: CURRENT POSITION 0 Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::syncState stateService stop Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::syncState currentStatus stop Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:57 pi5dev volumio[6103]: info: No code Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:48:57 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:48:57 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:48:58 pi5dev sudo[6597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 12 14:48:58 pi5dev sudo[6597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 14:48:58 pi5dev autossh[5038]: received signal to exit (15) Apr 12 14:48:58 pi5dev systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Apr 12 14:48:58 pi5dev systemd[1]: sshtunnel.service: Deactivated successfully. Apr 12 14:48:58 pi5dev systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Apr 12 14:48:58 pi5dev systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 12 14:48:58 pi5dev sudo[6597]: pam_unix(sudo:session): session closed for user root Apr 12 14:48:59 pi5dev volumio[6103]: info: Remote SSH Started Apr 12 14:48:59 pi5dev autossh[6600]: port set to 0, monitoring disabled Apr 12 14:48:59 pi5dev autossh[6600]: starting ssh (count 1) Apr 12 14:48:59 pi5dev autossh[6600]: ssh child pid is 6603 Apr 12 14:48:59 pi5dev volumiossh-tunnel[6603]: Warning: Permanently added '[eu3.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 12 14:48:59 pi5dev volumio[6103]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 12 14:48:59 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:48:59 pi5dev volumio[6103]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.dQFd7rFMkUZnTXfKxRPos4Ns44L2.96e25e8b036fdbb047a6171fc7e87d28.state.status' Apr 12 14:48:59 pi5dev volumio[6103]: info: MRS: Getting audio outputs on start Apr 12 14:48:59 pi5dev volumio[6103]: info: MRS: Requesting all other devices output Apr 12 14:48:59 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:48:59 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:00 pi5dev volumio[6103]: info: TidalConnect service started! Apr 12 14:49:00 pi5dev volumio[6103]: [Metrics] CommandRouter: 19s 960.37ms Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::volumiosetStartupVolume Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:49:00 pi5dev volumio[6103]: info: VolumeController:: Setting startup Volume 65 Apr 12 14:49:00 pi5dev volumio[6103]: info: VolumeController::SetAlsaVolume65 Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::Close All Modals sent Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::Close All Modals sent Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:00 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:00 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:00 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:01 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 12 14:49:01 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 12 14:49:01 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 12 14:49:02 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:02 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:03 pi5dev volumio[6103]: error: Failed request for metavolumio API Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 12 14:49:07 pi5dev volumio[6103]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetState Apr 12 14:49:07 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/ba-transport.c:319: New A2DP transport: 15 Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:672 W:1008 Apr 12 14:49:07 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 16 Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Playback started, enabling output Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioStop Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::stop Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::serviceStop Apr 12 14:49:07 pi5dev volumio[6103]: info: Received STOP, but no service to execute it Apr 12 14:49:07 pi5dev dbus-daemon[974]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.88" (uid=1000 pid=6103 comm="/usr/bin/node /volumio/index.js") interface="(unset)" member="(unset)" error name="com.github.dbus_next.Error" requested_reply="0" destination=":1.2" (uid=0 pid=973 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [AAMP] Modular pipeline enabled - using default ALSA route: volumio Apr 12 14:49:07 pi5dev bluetoothd[973]: Adv Monitor app :1.98 disconnected from D-Bus Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Detected connected BT MAC: 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Spawning bluealsa-aplay with args: --profile-a2dp --pcm=volumio --pcm-buffer-time=500000 --pcm-period-time=100000 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [metaCache] Loaded metadata for 5C:17:CF:0D:C0:70 from file Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Loaded metadata from cache for 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_5C_17_CF_0D_C0_70/a2dpsnk/source Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6626] D: aplay.c:904: Creating IO worker 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: bluealsa-aplay: [6626] D: aplay.c:1320: Starting main loop Apr 12 14:49:07 pi5dev volumio[6103]: bluealsa-aplay: [6627] D: aplay.c:577: Opening BlueALSA source PCM: /org/bluealsa/hci0/dev_5C_17_CF_0D_C0_70/a2dpsnk/source Apr 12 14:49:07 pi5dev volumio[6103]: bluealsa-aplay: [6627] D: aplay.c:603: Starting IO loop Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received new metadata for 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-5C:17:CF:0D:C0:70.json Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 5C:17:CF:0D:C0:70 Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Playback started, enabling output Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:07 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:07 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:07 pi5dev bluealsa[1126]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Apr 12 14:49:07 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:732: Opening ALSA playback PCM: name=volumio channels=2 rate=44100 Apr 12 14:49:07 pi5dev volumio[6103]: bluealsa-aplay: [6627] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Apr 12 14:49:07 pi5dev volumio[6103]: bluealsa-aplay: [6627] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Apr 12 14:49:07 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 12 14:49:07 pi5dev volumio[6103]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Apr 12 14:49:07 pi5dev volumio[6103]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Apr 12 14:49:07 pi5dev volumio[6103]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Apr 12 14:49:07 pi5dev volumio[6103]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Apr 12 14:49:07 pi5dev volumio[6103]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Apr 12 14:49:07 pi5dev volumio[6103]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Apr 12 14:49:07 pi5dev volumio[6103]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Apr 12 14:49:07 pi5dev volumio[6103]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 12 14:49:07 pi5dev volumio[6103]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 14:49:07 pi5dev volumio[6103]: info: BOOT COMPLETED Apr 12 14:49:08 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:08 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:49:08 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Apr 12 14:49:08 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:08 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:08 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:08 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 16 Apr 12 14:49:08 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:08 pi5dev bluealsa[1126]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Apr 12 14:49:08 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:49:08 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:08 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:08 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 14:49:09 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:09 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:09 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:09 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:09 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:09 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:09 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:643: BT device marked as inactive: 5C:17:CF:0D:C0:70 Apr 12 14:49:10 pi5dev volumio[6103]: info: CoreCommandRouter::volumioNext Apr 12 14:49:10 pi5dev volumio[6103]: info: CoreStateMachine::next Apr 12 14:49:10 pi5dev volumio[6103]: info: WARNING: No next method for plugin [object Object] Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::volumioGetBrowseSources Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 14:49:12 pi5dev volumio-remote-updater[996]: No test mode Apr 12 14:49:12 pi5dev volumio-remote-updater[996]: Alpha test mode enabled Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 12 14:49:12 pi5dev volumio[6103]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 12 14:49:12 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 12 14:49:13 pi5dev volumio[6103]: error: Failed request for metavolumio API Apr 12 14:49:14 pi5dev volumio[6103]: info: CoreCommandRouter::volumioNext Apr 12 14:49:14 pi5dev volumio[6103]: info: CoreStateMachine::next Apr 12 14:49:14 pi5dev volumio[6103]: info: WARNING: No next method for plugin [object Object] Apr 12 14:49:17 pi5dev volumio[6103]: info: CoreCommandRouter::volumioNext Apr 12 14:49:17 pi5dev volumio[6103]: info: CoreStateMachine::next Apr 12 14:49:17 pi5dev volumio[6103]: info: WARNING: No next method for plugin [object Object] Apr 12 14:49:20 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received new metadata for 5C:17:CF:0D:C0:70 Apr 12 14:49:20 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-5C:17:CF:0D:C0:70.json Apr 12 14:49:20 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:20 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:20 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:20 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:20 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:20 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:22 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:22 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:22 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:22 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:22 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:22 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::volumioNext Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreStateMachine::next Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] next Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: sendNext -> calling D-Bus Next() Apr 12 14:49:24 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/ba-transport.c:319: New A2DP transport: 17 Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/ba-transport.c:320: A2DP socket MTU: 17: R:672 W:1008 Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 5C:17:CF:0D:C0:70 Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Playback started, enabling output Apr 12 14:49:24 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [17]: 15 Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:24 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 12 14:49:24 pi5dev bluealsa[1126]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:732: Opening ALSA playback PCM: name=volumio channels=2 rate=44100 Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Apr 12 14:49:24 pi5dev volumio[6103]: bluealsa-aplay: [6627] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received new metadata for 5C:17:CF:0D:C0:70 Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [metaCache] Saved metadata to /tmp/bluetooth-cache/meta-5C:17:CF:0D:C0:70.json Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:24 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:24 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:24 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:24 pi5dev volumio[6103]: error: Failed request for metavolumio API Apr 12 14:49:25 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:25 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from 5C:17:CF:0D:C0:70 Apr 12 14:49:25 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Apr 12 14:49:25 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:25 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:25 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:25 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:25 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [17]: 15 Apr 12 14:49:25 pi5dev bluealsa[1126]: ../src/ba-transport.c:381: Closing A2DP transport: 17 Apr 12 14:49:25 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:49:25 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:25 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:25 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:643: BT device marked as inactive: 5C:17:CF:0D:C0:70 Apr 12 14:49:26 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: Executing endpoint metavolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::volumioVolatilePlay Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [FUNC] play Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: sendPlay -> calling D-Bus Play() Apr 12 14:49:26 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/ba-transport.c:319: New A2DP transport: 15 Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:672 W:1008 Apr 12 14:49:26 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from 5C:17:CF:0D:C0:70 Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Playback started, enabling output Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::volumioStop Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 16 Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreStateMachine::stop Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreStateMachine::serviceStop Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::serviceStop Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Apr 12 14:49:26 pi5dev volumio[6103]: error: WARNING: No stop method for service [object Object] Apr 12 14:49:26 pi5dev dbus-daemon[974]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.88" (uid=1000 pid=6103 comm="/usr/bin/node /volumio/index.js") interface="(unset)" member="(unset)" error name="com.github.dbus_next.Error" requested_reply="0" destination=":1.2" (uid=0 pid=973 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::servicePushState Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:26 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:26 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:26 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:26 pi5dev bluealsa[1126]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:732: Opening ALSA playback PCM: name=volumio channels=2 rate=44100 Apr 12 14:49:26 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [6627] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Apr 12 14:49:26 pi5dev volumio[6103]: bluealsa-aplay: [6627] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Apr 12 14:49:26 pi5dev volumio[6103]: info: touch_display: Setting screensaver timeout to 0 seconds. Apr 12 14:49:30 pi5dev volumio[6103]: info: MRS: Found cast device: Chromecast-Ultra-bb5475a65116e0c6bfcdcd498eee7139 Apr 12 14:49:32 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: Volume Apr 12 14:49:32 pi5dev bluealsa[1126]: bluez.c:1502: Updating A2DP volume: 81 [-6.48 dB] Apr 12 14:49:32 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] registerVolumeHandler: MAC = 5C:17:CF:0D:C0:70, rawVolume = 81 Apr 12 14:49:32 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received volume: raw = 81, scaled = 64 Apr 12 14:49:32 pi5dev volumio[6103]: info: VolumeController::SetAlsaVolume64 Apr 12 14:49:32 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 64 - forwarding to Bluetooth device Apr 12 14:49:32 pi5dev dbus-daemon[974]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.88" (uid=1000 pid=6103 comm="/usr/bin/node /volumio/index.js") interface="(unset)" member="(unset)" error name="com.github.dbus_next.Error" requested_reply="0" destination=":1.2" (uid=0 pid=973 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 12 14:49:32 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:32 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:32 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:32 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:32 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:33 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] registerVolumeHandler: MAC = 5C:17:CF:0D:C0:70, rawVolume = 85 Apr 12 14:49:33 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: Received volume: raw = 85, scaled = 67 Apr 12 14:49:33 pi5dev volumio[6103]: info: VolumeController::SetAlsaVolume67 Apr 12 14:49:33 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 67 - forwarding to Bluetooth device Apr 12 14:49:33 pi5dev bluealsa[1126]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: Volume Apr 12 14:49:33 pi5dev bluealsa[1126]: bluez.c:1502: Updating A2DP volume: 85 [-5.79 dB] Apr 12 14:49:33 pi5dev dbus-daemon[974]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.88" (uid=1000 pid=6103 comm="/usr/bin/node /volumio/index.js") interface="(unset)" member="(unset)" error name="com.github.dbus_next.Error" requested_reply="0" destination=":1.2" (uid=0 pid=973 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 12 14:49:33 pi5dev volumio[6103]: info: CoreStateMachine::pushState Apr 12 14:49:33 pi5dev volumio[6103]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 14:49:33 pi5dev volumio[6103]: info: CoreCommandRouter::volumioPushState Apr 12 14:49:33 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output update for this device Apr 12 14:49:33 pi5dev volumio[6103]: info: MRS: Pushing multiroomSync output Apr 12 14:49:36 pi5dev volumio[6103]: info: VolumeController::SetAlsaVolume49 Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 49 - forwarding to Bluetooth device Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [VOLUME HOOK] Intercepted volume 49 - forwarding to Bluetooth device Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] self.currentMAC = 5C:17:CF:0D:C0:70 Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] transportManager.currentMAC = undefined Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] MAC resolved for push = 5C:17:CF:0D:C0:70 Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: [DEBUG] Capabilities for 5C:17:CF:0D:C0:70: {"Volume":true} Apr 12 14:49:36 pi5dev volumio[6103]: ------------------------------------ BT MESSAGE: pushVolumeToDevice: Device does not support D-Bus volume control (Volume method missing or inactive player) Apr 12 14:49:36 pi5dev volumio[6103]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 14:49:36 pi5dev volumio[6103]: TypeError: self.setInternalVolume is not a function Apr 12 14:49:36 pi5dev volumio[6103]: at BluetoothInterface.pushVolumeToDevice (/myvolumio/plugins/audio_interface/bluetooth/index.js:117:10) Apr 12 14:49:36 pi5dev volumio[6103]: at self.commandRouter.volumeControl.setVolume (/myvolumio/plugins/audio_interface/bluetooth/index.js:626:16) Apr 12 14:49:36 pi5dev volumio[6103]: at CoreVolumeController.alsavolume (/volumio/app/volumecontrol.js:460:16) Apr 12 14:49:36 pi5dev volumio[6103]: at CoreCommandRouter.volumiosetvolume (/volumio/app/index.js:135:35) Apr 12 14:49:36 pi5dev volumio[6103]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:304:33) Apr 12 14:49:36 pi5dev volumio[6103]: at Socket.emit (node:events:514:28) Apr 12 14:49:36 pi5dev volumio[6103]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 12 14:49:36 pi5dev volumio[6103]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Apr 12 14:49:36 pi5dev volumio[6103]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 14:49:36 pi5dev sudo[6712]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-04-12 14:48' Apr 12 14:49:36 pi5dev sudo[6712]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="8a3b6fcf0dbd7d42207332f6d209906dd2daab56" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Apr 10 17:13:43 UTC 2025" VOLUMIO_VERSION="0.053" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="71bb4de3e1e8e1ea68014647223087d0"