-- Logs begin at Fri 2025-09-12 07:37:55 CEST, end at Fri 2025-09-12 07:45:37 CEST. -- Sep 12 07:44:04 volumio volumio[1135]: info: ___Python pygame already installed Sep 12 07:44:04 volumio volumio[1135]: info: ___Python sockt-IO already installed Sep 12 07:44:04 volumio volumio[1135]: info: ___Install python pillow... Sep 12 07:44:04 volumio sudo[3272]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/tar -xzf /data/plugins/user_interface/peppy_screensaver/dependencies/PIL.tar.gz -C /usr/local/lib/python3.7/dist-packages Sep 12 07:44:04 volumio sudo[3272]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:04 volumio sudo[3272]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:05 volumio volumio[1135]: info: ___Python pyscreenshot already installed Sep 12 07:44:05 volumio sudo[3293]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rd /data/plugins/user_interface/peppy_screensaver/dependencies Sep 12 07:44:05 volumio sudo[3293]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:05 volumio sudo[3293]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:05 volumio volumio[1135]: info: ___Modify PeppyMeter config for Volumio... Sep 12 07:44:05 volumio volumio[1135]: info: ___Modify PeppySpectrum config for Volumio... Sep 12 07:44:05 volumio sudo[2938]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:05 volumio volumio[1135]: info: ___Finished Sep 12 07:44:05 volumio volumio[1135]: Plugin install end detected on script Sep 12 07:44:05 volumio volumio[1135]: info: Install script completed Sep 12 07:44:05 volumio volumio[1135]: info: Adding reference to registry Sep 12 07:44:05 volumio volumio[1135]: info: Done installing plugin. Sep 12 07:44:05 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 12 07:44:05 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 12 07:44:05 volumio volumio[1135]: info: Folder /tmp/plugins removed Sep 12 07:44:05 volumio volumio[1135]: info: Folder /tmp/downloaded_plugin.zip removed Sep 12 07:44:05 volumio volumio[1135]: info: Folder /data/temp removed Sep 12 07:44:22 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:22 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:24 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:44:24 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:44:24 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:44:24 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:44:24 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:44:24 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:44:24 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 12 07:44:24 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 12 07:44:27 volumio volumio[1135]: info: Enabling plugin peppy_screensaver Sep 12 07:44:27 volumio volumio[1135]: info: Loading plugin "peppy_screensaver"... Sep 12 07:44:27 volumio volumio[1135]: info: Preparing to generate the ALSA configuration file Sep 12 07:44:27 volumio volumio[1135]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Sep 12 07:44:27 volumio volumio[1135]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Sep 12 07:44:27 volumio volumio[1135]: info: Reading ALSA contributions from plugins. Sep 12 07:44:27 volumio volumio[1135]: info: Asound.conf file written Sep 12 07:44:27 volumio sudo[3350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Sep 12 07:44:27 volumio sudo[3350]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio sudo[3350]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:27 volumio volumio[1135]: info: Output device has changed, restarting MPD Sep 12 07:44:27 volumio sudo[3358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 12 07:44:27 volumio sudo[3358]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio volumio[1135]: info: Output device has changed, restarting Shairport Sync Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:27 volumio sudo[3358]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:27 volumio sudo[3361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 12 07:44:27 volumio sudo[3361]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio systemd[1]: Stopping Music Player Daemon... Sep 12 07:44:27 volumio volumio[1135]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 12 07:44:27 volumio volumio[1135]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: QobuzConnect: setDeactiveState invoked Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:27 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:27 volumio vtcs[2366]: [2025-09-12 07:44:27.867] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Sep 12 07:44:27 volumio vtcs[2366]: [2025-09-12 07:44:27.867] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Sep 12 07:44:27 volumio systemd[1]: mpd.service: Succeeded. Sep 12 07:44:27 volumio systemd[1]: Stopped Music Player Daemon. Sep 12 07:44:27 volumio volumio[1135]: info: PLUGIN START: peppy_screensaver Sep 12 07:44:27 volumio sudo[3370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Sep 12 07:44:27 volumio sudo[3370]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio systemd[1]: Starting Music Player Daemon... Sep 12 07:44:27 volumio volumio[1135]: info: Loading i18n strings for locale pl Sep 12 07:44:27 volumio volumio[1135]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Sep 12 07:44:27 volumio volumio[1135]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Sep 12 07:44:27 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Sep 12 07:44:27 volumio volumio[1135]: info: /tmp/myfifo created Sep 12 07:44:27 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Sep 12 07:44:27 volumio systemd[1]: vtcs.service: Succeeded. Sep 12 07:44:27 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Sep 12 07:44:27 volumio volumio[1135]: info: /tmp/myfifosa created Sep 12 07:44:27 volumio sudo[3370]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:27 volumio sudo[3369]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 12 07:44:27 volumio sudo[3369]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio sudo[3369]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:27 volumio sudo[3379]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-dummy index=7 pcm_substreams=1 fake_buffer=0 Sep 12 07:44:27 volumio sudo[3379]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:27 volumio sudo[3379]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:27 volumio volumio[1135]: info: snd-dummy loaded Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startShairportSync Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:27 volumio volumio[1135]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 12 07:44:27 volumio volumio[1135]: info: Done. Sep 12 07:44:28 volumio sudo[3402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Sep 12 07:44:28 volumio sudo[3402]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio sudo[3402]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio sudo[3409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Sep 12 07:44:28 volumio sudo[3409]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:28 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:28 volumio volumio[1135]: error: peppy_screensaver: Error unmount /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl Error: Command failed: /bin/df /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl | /bin/grep /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl && /bin/echo volumio | /usr/bin/sudo -S /bin/umount /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl Sep 12 07:44:28 volumio volumio[1135]: info: MPD Permissions set Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio sudo[3409]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: Starting Shairport Sync Sep 12 07:44:28 volumio sudo[3411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Sep 12 07:44:28 volumio sudo[3411]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio volumio[1135]: info: Starting Shairport Sync Sep 12 07:44:28 volumio systemd[1]: Stopping Volumio Qobuz Connect Service... Sep 12 07:44:28 volumio qobuz-connect[2321]: 20250912 07:44:28.064 [2321.2321] INFO SampleApp: Stopping Local configuration server Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio sudo[3418]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 12 07:44:28 volumio sudo[3418]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio sudo[3420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 12 07:44:28 volumio sudo[3420]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio qobuz-connect[2321]: 20250912 07:44:28.074 [2321.2321] INFO SampleApp: shat down connection on UNIX socket Sep 12 07:44:28 volumio volumio[1135]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Sep 12 07:44:28 volumio volumio[1135]: info: QobuzConnect: setDeactiveState invoked Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:28 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:28 volumio systemd[1]: qobuz-connect.service: Succeeded. Sep 12 07:44:28 volumio systemd[1]: Stopped Volumio Qobuz Connect Service. Sep 12 07:44:28 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 07:44:28 volumio systemd[1]: Started Volumio Qobuz Connect Service. Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 12 07:44:28 volumio sudo[3411]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 07:44:28 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 12 07:44:28 volumio sudo[3418]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio sudo[3420]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: info: Shairport-Sync Started Sep 12 07:44:28 volumio volumio[1135]: info: Executing endpoint qc_getconfig Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.128 [3423.3423] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Sep 12 07:44:28 volumio volumio[1135]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Sep 12 07:44:28 volumio volumio[1135]: info: QobuzConnect: QOBUZ Connect daemon connected Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.129 [3423.3423] INFO VolumeManager: [0x19fc970]: Setting new playback volume: 75 Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.129 [3423.3423] INFO VolumeManager: [0x19fc970]: Setting new mute state: 0 Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.129 [3423.3423] INFO QobuzConnect: [0x19fd340]: Client initialized! Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.129 [3423.3423] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.132 [3423.3423] INFO LocalConfigManager: [0x19fc250]: Starting Local Configuration server Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.132 [3423.3423] INFO SampleApp: Starting Local configuration server Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.132 [3423.3423] INFO SampleApp: Connected to UNIX socket client 0x19f1f60 Sep 12 07:44:28 volumio sudo[3431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount --bind /tmp/mpd.conf.tmpl /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Sep 12 07:44:28 volumio sudo[3431]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio sudo[3431]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: mpd , createMPDFile Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio sudo[3436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio sudo[3436]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio sudo[3436]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: MPD Permissions set Sep 12 07:44:28 volumio qobuz-connect[3423]: 20250912 07:44:28.279 [3423.3423] INFO SampleApp: Playback volume changed: 75 Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:28 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 12 07:44:28 volumio mpd[3382]: Sep 12 07:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 12 07:44:28 volumio systemd[1]: Started Music Player Daemon. Sep 12 07:44:28 volumio sudo[3361]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: error: updateQueue error: null Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Sep 12 07:44:28 volumio sudo[3446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 12 07:44:28 volumio sudo[3446]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio systemd[1]: Stopping Music Player Daemon... Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio systemd[1]: mpd.service: Succeeded. Sep 12 07:44:28 volumio systemd[1]: Stopped Music Player Daemon. Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 07:44:28 volumio systemd[1]: Starting Music Player Daemon... Sep 12 07:44:28 volumio volumio[1135]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 07:44:28 volumio sudo[3448]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 12 07:44:28 volumio sudo[3448]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:28 volumio sudo[3448]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 12 07:44:28 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:28 volumio mpd[3451]: Sep 12 07:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 12 07:44:28 volumio systemd[1]: Started Music Player Daemon. Sep 12 07:44:28 volumio sudo[3446]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:28 volumio volumio[1135]: error: updateQueue error: null Sep 12 07:44:30 volumio volumio[1135]: info: TidalConnect service stoped! Sep 12 07:44:31 volumio volumio[1135]: info: TidalConnect service stoped! Sep 12 07:44:31 volumio volumio[1135]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Sep 12 07:44:31 volumio volumio[1135]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Sep 12 07:44:31 volumio sudo[3463]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Sep 12 07:44:31 volumio sudo[3463]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 07:44:31 volumio systemd[1]: Started Volumio Tidal Connect Service. Sep 12 07:44:31 volumio sudo[3463]: pam_unix(sudo:session): session closed for user root Sep 12 07:44:31 volumio volumio[1135]: info: Executing endpoint tc_getconfig Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Sep 12 07:44:31 volumio vtcs[3465]: STARTING TidalConnect services, version: 1.5.1-beta1 Sep 12 07:44:31 volumio vtcs[3465]: STARTED TidalConnect services. Sep 12 07:44:31 volumio volumio[1135]: info: Executing endpoint tc_connect Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Sep 12 07:44:31 volumio volumio[1135]: info: Connecting to TidalConnect Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: 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} Sep 12 07:44:31 volumio volumio[1135]: verbose: CURRENT POSITION 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::syncState stateService stop Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus stop Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: No code Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: 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} Sep 12 07:44:31 volumio volumio[1135]: verbose: CURRENT POSITION 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::syncState stateService stop Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus stop Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: No code Sep 12 07:44:31 volumio volumio[1135]: info: CoreStateMachine::pushState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output update for this device Sep 12 07:44:31 volumio volumio[1135]: info: MRS: Pushing multiroomSync output Sep 12 07:44:31 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:44:31 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:44:34 volumio volumio[1135]: info: TidalConnect service started! Sep 12 07:44:44 volumio volumio[1135]: info: CALLMETHOD: user_interface peppy_screensaver savePeppyMeterConf [object Object] Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , savePeppyMeterConf Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 12 07:44:44 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:45:05 volumio volumio[1135]: info: CALLMETHOD: user_interface peppy_screensaver saveVUMeterConf [object Object] Sep 12 07:45:05 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , saveVUMeterConf Sep 12 07:45:05 volumio volumio[1135]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 12 07:45:05 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 12 07:45:10 volumio volumio[1135]: info: CoreCommandRouter::volumioGetState Sep 12 07:45:10 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Sep 12 07:45:12 volumio volumio[1135]: info: CoreCommandRouter::volumioGetQueue Sep 12 07:45:12 volumio volumio[1135]: info: CoreStateMachine::getQueue Sep 12 07:45:12 volumio volumio[1135]: info: CorePlayQueue::getQueue Sep 12 07:45:13 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:45:13 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:45:13 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:45:13 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:45:13 volumio volumio[1135]: info: Executing endpoint metavolumio Sep 12 07:45:13 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 07:45:13 volumio volumio[1135]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/none.svg' Sep 12 07:45:16 volumio volumio[1135]: info: Preload queue cleared Sep 12 07:45:16 volumio volumio[1135]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 12 07:45:16 volumio volumio[1135]: info: CoreStateMachine::ClearQueue Sep 12 07:45:16 volumio volumio[1135]: info: CoreStateMachine::stop Sep 12 07:45:16 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 07:45:16 volumio volumio[1135]: info: CorePlayQueue::clearPlayQueue Sep 12 07:45:16 volumio volumio[1135]: info: CorePlayQueue::saveQueue Sep 12 07:45:16 volumio volumio[1135]: info: CoreCommandRouter::volumioPushQueue Sep 12 07:45:16 volumio volumio[1135]: info: CoreStateMachine::addQueueItems Sep 12 07:45:16 volumio volumio[1135]: info: CorePlayQueue::addQueueItems Sep 12 07:45:16 volumio volumio[1135]: info: Preload queue cleared Sep 12 07:45:16 volumio volumio[1135]: info: Adding Item to queue: upnp/folder/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdL0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzLm0zdQ== Sep 12 07:45:16 volumio volumio[1135]: info: Exploding uri upnp/folder/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdL0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzLm0zdQ== in service upnp_browser Sep 12 07:45:16 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAxLiBMb3ZlIElzIEEgU3RyYW5nZXIuZmxhYw== Sep 12 07:45:16 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAxLiBMb3ZlIElzIEEgU3RyYW5nZXIuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: CoreCommandRouter::volumioPushQueue Sep 12 07:45:28 volumio volumio[1135]: info: CorePlayQueue::saveQueue Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::updateTrackBlock Sep 12 07:45:28 volumio volumio[1135]: info: CorePlayQueue::getTrackBlock Sep 12 07:45:28 volumio volumio[1135]: info: CoreCommandRouter::volumioPlay Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::play index 1 Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::addQueueItems Sep 12 07:45:28 volumio volumio[1135]: info: CorePlayQueue::addQueueItems Sep 12 07:45:28 volumio volumio[1135]: info: Preload queue cleared Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAyLiBTd2VldCBEcmVhbXMuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAyLiBTd2VldCBEcmVhbXMuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAzLiBXaG8ncyBUaGF0IEdpcmwuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzAzLiBXaG8ncyBUaGF0IEdpcmwuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA0LiBSaWdodCBCeSBZb3VyIFNpZGUuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA0LiBSaWdodCBCeSBZb3VyIFNpZGUuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA1LiBIZXJlIENvbWVzIFRoZSBSYWluIEFnYWluLmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA1LiBIZXJlIENvbWVzIFRoZSBSYWluIEFnYWluLmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA2LiBUaGVyZSBNdXN0IEJlIEFuIEFuZ2VsIChQbGF5aW5nIFdpdGggTXkgSGVhcnQpLmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA2LiBUaGVyZSBNdXN0IEJlIEFuIEFuZ2VsIChQbGF5aW5nIFdpdGggTXkgSGVhcnQpLmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA3LiBTaXN0ZXJzIEFyZSBEb2luJyBJdCBGb3IgVGhlbXNlbHZlcy5mbGFj Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA3LiBTaXN0ZXJzIEFyZSBEb2luJyBJdCBGb3IgVGhlbXNlbHZlcy5mbGFj in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA4LiBJdCdzIEFscmlnaHQgKEJhYnkncyBDb21pbmcgQmFjaykuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA4LiBJdCdzIEFscmlnaHQgKEJhYnkncyBDb21pbmcgQmFjaykuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA5LiBXaGVuIFRvbW9ycm93IENvbWVzLmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzA5LiBXaGVuIFRvbW9ycm93IENvbWVzLmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEwLiBZb3UgSGF2ZSBQbGFjZWQgQSBDaGlsbCBJbiBNeSBIZWFydC5mbGFj Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEwLiBZb3UgSGF2ZSBQbGFjZWQgQSBDaGlsbCBJbiBNeSBIZWFydC5mbGFj in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzExLiBNaXJhY2xlIE9mIExvdmUuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzExLiBNaXJhY2xlIE9mIExvdmUuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEyLiBTZXggQ3JpbWUgKDE5ODQpLmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEyLiBTZXggQ3JpbWUgKDE5ODQpLmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEzLiBUaG9ybiBJbiBNeSBTaWRlLmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzEzLiBUaG9ybiBJbiBNeSBTaWRlLmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE0LiBEb24ndCBBc2sgTWUgV2h5LmZsYWM= Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE0LiBEb24ndCBBc2sgTWUgV2h5LmZsYWM= in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE1LiBBbmdlbC5mbGFj Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE1LiBBbmdlbC5mbGFj in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE2LiBXb3VsZCBJIExpZSBUbyBZb3UuZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE2LiBXb3VsZCBJIExpZSBUbyBZb3UuZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE3LiBNaXNzaW9uYXJ5IE1hbi5mbGFj Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE3LiBNaXNzaW9uYXJ5IE1hbi5mbGFj in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE4LiBJIE5lZWQgQSBNYW4uZmxhYw== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdLzE4LiBJIE5lZWQgQSBNYW4uZmxhYw== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: Adding Item to queue: upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdL0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzLmN1ZQ== Sep 12 07:45:28 volumio volumio[1135]: info: Exploding uri upnp/http://192.168.1.122:1843/ContentDirectory/71e3052c-d7cc-f58b-3e9d-ed0a0ef49141/control.xml@L3Zhci9tZWRpYS9TYW1iYS9IREQxMFRiL0hERDRUYi9NdXphLzI4LmxpcC4yMDI1L0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzICgxOTkxKSAgW0ZMQUNdL0V1cnl0aG1pY3MgLSBHcmVhdGVzdCBIaXRzLmN1ZQ== in service upnp_browser Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::stop Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::play index undefined Sep 12 07:45:28 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 07:45:28 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Sep 12 07:45:29 volumio volumio[1135]: info: CoreCommandRouter::volumioPushQueue Sep 12 07:45:29 volumio volumio[1135]: info: CorePlayQueue::saveQueue Sep 12 07:45:29 volumio volumio[1135]: info: CoreStateMachine::updateTrackBlock Sep 12 07:45:29 volumio volumio[1135]: info: CorePlayQueue::getTrackBlock Sep 12 07:45:35 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 12 07:45:35 volumio volumio[1135]: info: Preload queue cleared Sep 12 07:45:37 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 12 07:45:37 volumio volumio[1135]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 07:45:37 volumio volumio[1135]: TypeError: Cannot read property 'length' of undefined Sep 12 07:45:37 volumio volumio[1135]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 12 07:45:37 volumio volumio[1135]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 12 07:45:37 volumio volumio[1135]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 12 07:45:37 volumio volumio[1135]: at Parser.emit (events.js:315:20) Sep 12 07:45:37 volumio volumio[1135]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 12 07:45:37 volumio volumio[1135]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 12 07:45:37 volumio volumio[1135]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 12 07:45:37 volumio volumio[1135]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 12 07:45:37 volumio volumio[1135]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 12 07:45:37 volumio volumio[1135]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 12 07:45:37 volumio volumio[1135]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 12 07:45:37 volumio volumio[1135]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 12 07:45:37 volumio volumio[1135]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 12 07:45:37 volumio volumio[1135]: at IncomingMessage.emit (events.js:327:22) Sep 12 07:45:37 volumio volumio[1135]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 12 07:45:37 volumio volumio[1135]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 12 07:45:37 volumio volumio[1135]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 07:45:37 volumio sudo[3648]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-12 07:44 Sep 12 07:45:37 volumio sudo[3648]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="95d9088e5dcb3a55aabfe7f209b9ae00946f3ec5" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9a3927796ae9ab3a5a247866bf574288cd09ee64" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 04 Sep 2025 04:11:35 PM CEST" VOLUMIO_VERSION="3.845" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d8c10ad904a299b47c7499a1cf239286"