May 31 19:44:04 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 19:44:04 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 31 19:44:12 volumioht volumio[1168]: info: Stopping peppyspectrum service May 31 19:44:12 volumioht volumio[1168]: info: CoreStateMachine::stop May 31 19:44:12 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 19:44:12 volumioht volumio[1168]: info: Disabling plugin peppyspectrum May 31 19:44:12 volumioht volumio[1168]: info: Preparing to generate the ALSA configuration file May 31 19:44:12 volumioht volumio[1168]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 19:44:12 volumioht volumio[1168]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 31 19:44:12 volumioht volumio[1168]: info: Reading ALSA contributions from plugins. May 31 19:44:12 volumioht volumio[1168]: info: Asound.conf file written May 31 19:44:12 volumioht sudo[3901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:12 volumioht sudo[3901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht sudo[3905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 31 19:44:12 volumioht sudo[3905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht sudo[3901]: pam_unix(sudo:session): session closed for user root May 31 19:44:12 volumioht sudo[3905]: pam_unix(sudo:session): session closed for user root May 31 19:44:12 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 31 19:44:12 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 31 19:44:12 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 31 19:44:12 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 May 31 19:44:12 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 May 31 19:44:12 volumioht volumio[1168]: info: Output device has changed, restarting MPD May 31 19:44:12 volumioht volumio[1168]: info: Output device has changed, restarting Shairport Sync May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:12 volumioht sudo[3913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 19:44:12 volumioht sudo[3913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht sudo[3913]: pam_unix(sudo:session): session closed for user root May 31 19:44:12 volumioht sudo[3917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 19:44:12 volumioht sudo[3917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht volumio[1168]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 19:44:12 volumioht volumio[1168]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: QobuzConnect: setDeactiveState invoked May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:12 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:12 volumioht vtcs[3762]: [2026-05-31 19:44:12.881] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 31 19:44:12 volumioht vtcs[3762]: [2026-05-31 19:44:12.881] [tisoc] [error] [SpkconServer.cpp:383] recv error. client fd=8 errorno=104 error=Connection reset by peer May 31 19:44:12 volumioht vtcs[3762]: [2026-05-31 19:44:12.881] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 31 19:44:12 volumioht volumio[1168]: info: Done. May 31 19:44:12 volumioht systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 19:44:12 volumioht sudo[3929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:12 volumioht sudo[3929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht sudo[3931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:12 volumioht sudo[3931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht systemd[1]: mpd.service: Deactivated successfully. May 31 19:44:12 volumioht systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 19:44:12 volumioht systemd[1]: mpd.service: Consumed 1.678s CPU time. May 31 19:44:12 volumioht systemd[1]: mpd.socket: Deactivated successfully. May 31 19:44:12 volumioht systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 19:44:12 volumioht systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 19:44:12 volumioht volumio[1168]: info: MPD Permissions set May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht sudo[3939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 19:44:12 volumioht sudo[3939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:12 volumioht volumio[1168]: info: Starting Shairport Sync May 31 19:44:13 volumioht sudo[3948]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 19:44:13 volumioht sudo[3948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 19:44:13 volumioht systemd[1]: Starting mpd.service - Music Player Daemon... May 31 19:44:13 volumioht sudo[3939]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 19:44:13 volumioht systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... May 31 19:44:13 volumioht systemd[1]: shairport-sync.service: Deactivated successfully. May 31 19:44:13 volumioht systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:13 volumioht systemd[1]: shairport-sync.service: Consumed 1.585s CPU time. May 31 19:44:13 volumioht sudo[3951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 19:44:13 volumioht sudo[3951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:13 volumioht systemd[1]: vtcs.service: Deactivated successfully. May 31 19:44:13 volumioht sudo[3948]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. May 31 19:44:13 volumioht volumio[1168]: info: Shairport-Sync Started May 31 19:44:13 volumioht sudo[3929]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht sudo[3950]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 19:44:13 volumioht sudo[3950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 19:44:13 volumioht sudo[3931]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht sudo[3950]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 31 19:44:13 volumioht qobuz-connect[3786]: 20260531 19:44:13.188 [3786.3786] INFO SampleApp: Stopping Local configuration server May 31 19:44:13 volumioht volumio[1168]: info: Enabling plugin peppyspectrum May 31 19:44:13 volumioht volumio[1168]: info: Loading plugin "peppyspectrum"... May 31 19:44:13 volumioht volumio[1168]: info: Preparing to generate the ALSA configuration file May 31 19:44:13 volumioht volumio[1168]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 19:44:13 volumioht volumio[1168]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 31 19:44:13 volumioht volumio[1168]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 31 19:44:13 volumioht volumio[1168]: info: Reading ALSA contributions from plugins. May 31 19:44:13 volumioht volumio[1168]: info: Asound.conf file written May 31 19:44:13 volumioht sudo[3988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 31 19:44:13 volumioht sudo[3988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht sudo[3988]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 31 19:44:13 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 31 19:44:13 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 31 19:44:13 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 May 31 19:44:13 volumioht volumio[1168]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:7 use case configuration -2 May 31 19:44:13 volumioht volumio[1168]: info: Output device has changed, restarting MPD May 31 19:44:13 volumioht volumio[1168]: info: Output device has changed, restarting Shairport Sync May 31 19:44:13 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:13 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:13 volumioht sudo[3996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 19:44:13 volumioht sudo[3996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht volumio[1168]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 19:44:13 volumioht volumio[1168]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 19:44:13 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:13 volumioht volumio[1168]: info: QobuzConnect: setDeactiveState invoked May 31 19:44:13 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:13 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:13 volumioht sudo[3997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 19:44:13 volumioht sudo[3997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht sudo[3997]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht volumio[1168]: info: PLUGIN START: peppyspectrum May 31 19:44:13 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 31 19:44:13 volumioht systemd[1]: mpd.service: Deactivated successfully. May 31 19:44:13 volumioht systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 19:44:13 volumioht systemd[1]: mpd.socket: Deactivated successfully. May 31 19:44:13 volumioht systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 19:44:13 volumioht systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 19:44:13 volumioht sudo[4007]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:13 volumioht sudo[4007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht volumio[1168]: info: Preparing to generate the ALSA configuration file May 31 19:44:13 volumioht sudo[4011]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-aloop index=7 pcm_substreams=1 May 31 19:44:13 volumioht sudo[4011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:13 volumioht volumio[1168]: info: Done. May 31 19:44:13 volumioht systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 19:44:13 volumioht sudo[4011]: pam_unix(sudo:session): session closed for user root May 31 19:44:13 volumioht systemd[1]: Starting mpd.service - Music Player Daemon... May 31 19:44:13 volumioht sudo[4015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:13 volumioht sudo[4015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht sudo[4007]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht volumio[1168]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf May 31 19:44:14 volumioht volumio[1168]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 31 19:44:14 volumioht volumio[1168]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf May 31 19:44:14 volumioht volumio[1168]: info: Reading ALSA contributions from plugins. May 31 19:44:14 volumioht volumio[1168]: info: snd_dummy loaded May 31 19:44:14 volumioht sudo[4022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 19:44:14 volumioht sudo[4022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht sudo[4015]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht sudo[4022]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht volumio[1168]: info: MPD Permissions set May 31 19:44:14 volumioht volumio[1168]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht sudo[4027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 19:44:14 volumioht sudo[4027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:14 volumioht sudo[4013]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht sudo[4013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 19:44:14 volumioht sudo[4013]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht volumio[1168]: info: Starting Shairport Sync May 31 19:44:14 volumioht volumio[1168]: info: Asound.conf file unchanged, so no further update is needed May 31 19:44:14 volumioht volumio[1168]: info: Output device has changed, restarting MPD May 31 19:44:14 volumioht sudo[4037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 19:44:14 volumioht sudo[4037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht sudo[4042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 19:44:14 volumioht sudo[4042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht volumio[1168]: info: Output device has changed, restarting Shairport Sync May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:14 volumioht systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 19:44:14 volumioht systemd[1]: shairport-sync.service: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:14 volumioht systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:14 volumioht sudo[4039]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 19:44:14 volumioht sudo[4037]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht sudo[4039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht sudo[4039]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht systemd[1]: mpd.service: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 19:44:14 volumioht systemd[1]: mpd.socket: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 19:44:14 volumioht systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 19:44:14 volumioht volumio[1168]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 19:44:14 volumioht volumio[1168]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: QobuzConnect: setDeactiveState invoked May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:14 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:14 volumioht systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 19:44:14 volumioht systemd[1]: Starting mpd.service - Music Player Daemon... May 31 19:44:14 volumioht sudo[4069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:14 volumioht sudo[4069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht sudo[4076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 19:44:14 volumioht sudo[4076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht volumio[1168]: info: MPD Permissions set May 31 19:44:14 volumioht volumio[1168]: info: Shairport-Sync Started May 31 19:44:14 volumioht sudo[4069]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht sudo[4067]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 19:44:14 volumioht sudo[4067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 19:44:14 volumioht sudo[4067]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht sudo[4082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 19:44:14 volumioht sudo[4082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 19:44:14 volumioht volumio[1168]: info: Starting Shairport Sync May 31 19:44:14 volumioht sudo[4076]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht sudo[4082]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht qobuz-connect[3786]: 20260531 19:44:14.535 [3786.3786] INFO SampleApp: shat down connection on UNIX socket May 31 19:44:14 volumioht volumio[1168]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 31 19:44:14 volumioht volumio[1168]: info: QobuzConnect: setDeactiveState invoked May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:14 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:14 volumioht systemd[1]: qobuz-connect.service: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 31 19:44:14 volumioht sudo[4095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 19:44:14 volumioht sudo[4095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 31 19:44:14 volumioht sudo[4027]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht sudo[3951]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 31 19:44:14 volumioht systemd[1]: qobuz-connect.service: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 31 19:44:14 volumioht sudo[4094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 19:44:14 volumioht sudo[4094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:14 volumioht systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 31 19:44:14 volumioht sudo[4095]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 19:44:14 volumioht systemd[1]: shairport-sync.service: Deactivated successfully. May 31 19:44:14 volumioht systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:14 volumioht volumio[1168]: info: Executing endpoint qc_getconfig May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 31 19:44:14 volumioht systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 19:44:14 volumioht sudo[4094]: pam_unix(sudo:session): session closed for user root May 31 19:44:14 volumioht volumio[1168]: info: Shairport-Sync Started May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.718 [4099.4099] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.723 [4099.4099] INFO VolumeManager: [0x5b5d48]: Setting new playback volume: 75 May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.723 [4099.4099] INFO VolumeManager: [0x5b5d48]: Setting new mute state: 0 May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.723 [4099.4099] INFO AudioStreamManager: [0x5b5aa0]: Setting new audio download buffer size: 1048576 May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.723 [4099.4099] INFO QobuzConnect: [0x5b6610]: Client initialized! May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.723 [4099.4099] INFO SampleApp: Starting Avahi advertising, name: Volumioht, service name: _qobuz-connect._tcp May 31 19:44:14 volumioht volumio[1168]: (node:1168) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pbeg listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit May 31 19:44:14 volumioht volumio[1168]: (Use `node --trace-warnings ...` to show where the warning was created) May 31 19:44:14 volumioht volumio[1168]: (node:1168) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 meta listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit May 31 19:44:14 volumioht volumio[1168]: (node:1168) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 prgr listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit May 31 19:44:14 volumioht volumio[1168]: (node:1168) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pvol listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit May 31 19:44:14 volumioht volumio[1168]: (node:1168) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 pend listeners added to [ShairportSyncReaderUDP]. Use emitter.setMaxListeners() to increase limit May 31 19:44:14 volumioht volumio[1168]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 31 19:44:14 volumioht volumio[1168]: info: QobuzConnect: QOBUZ Connect daemon connected May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.742 [4099.4099] INFO LocalConfigManager: [0x5b57c8]: Starting Local Configuration server May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.742 [4099.4099] INFO SampleApp: Starting Local configuration server May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.743 [4099.4099] INFO SampleApp: Connected to UNIX socket client 0x5a0818 May 31 19:44:14 volumioht qobuz-connect[4099]: 20260531 19:44:14.869 [4099.4099] INFO SampleApp: Playback volume changed: 75 May 31 19:44:14 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:14 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:15 volumioht mpd[4090]: 2026-05-31T19:44:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 19:44:15 volumioht systemd[1]: Started mpd.service - Music Player Daemon. May 31 19:44:15 volumioht sudo[3917]: pam_unix(sudo:session): session closed for user root May 31 19:44:15 volumioht sudo[3996]: pam_unix(sudo:session): session closed for user root May 31 19:44:15 volumioht sudo[4042]: pam_unix(sudo:session): session closed for user root May 31 19:44:15 volumioht volumio[1168]: error: MPD error: The expression evaluated to a falsy value: May 31 19:44:15 volumioht volumio[1168]: assert.ok(self.idling) May 31 19:44:15 volumioht volumio[1168]: error: The expression evaluated to a falsy value: May 31 19:44:15 volumioht volumio[1168]: assert.ok(self.idling) May 31 19:44:15 volumioht volumio[1168]: error: MPD error: The expression evaluated to a falsy value: May 31 19:44:15 volumioht volumio[1168]: assert.ok(self.idling) May 31 19:44:15 volumioht volumio[1168]: error: The expression evaluated to a falsy value: May 31 19:44:15 volumioht volumio[1168]: assert.ok(self.idling) May 31 19:44:15 volumioht volumio[1168]: error: updateQueue error: null May 31 19:44:16 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:16 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:16 volumioht volumio[1168]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:16 volumioht volumio[1168]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:16 volumioht sudo[4131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 19:44:16 volumioht sudo[4131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:16 volumioht systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. May 31 19:44:16 volumioht sudo[4131]: pam_unix(sudo:session): session closed for user root May 31 19:44:16 volumioht volumio[1168]: info: Executing endpoint tc_getconfig May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 31 19:44:16 volumioht vtcs[4134]: STARTING TidalConnect services, version: 1.6.1 May 31 19:44:16 volumioht vtcs[4134]: STARTED TidalConnect services. May 31 19:44:16 volumioht volumio[1168]: info: Executing endpoint tc_connect May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 31 19:44:16 volumioht volumio[1168]: info: Connecting to TidalConnect May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:16 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:16 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:16 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:16 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:16 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:16 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:16 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:16 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect May 31 19:44:16 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:16.496-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=300 volume=100 May 31 19:44:16 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:16.498-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:16 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:16.501-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=300 volume=100 May 31 19:44:16 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:16.502-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:16 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:16 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:16 volumioht sudo[4151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:16 volumioht sudo[4151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:16 volumioht sudo[4153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:16 volumioht sudo[4153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:16 volumioht volumio[1168]: info: touch_display: Setting screensaver timeout to 0 seconds. May 31 19:44:16 volumioht sudo[4151]: pam_unix(sudo:session): session closed for user root May 31 19:44:16 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:16 volumioht sudo[4153]: pam_unix(sudo:session): session closed for user root May 31 19:44:16 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:17 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:17 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:17 volumioht volumio[1168]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:17 volumioht volumio[1168]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:17 volumioht sudo[4168]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 19:44:17 volumioht sudo[4168]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:17 volumioht sudo[4168]: pam_unix(sudo:session): session closed for user root May 31 19:44:17 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:17 volumioht volumio[1168]: info: TidalConnect service stoped! May 31 19:44:17 volumioht volumio[1168]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:17 volumioht volumio[1168]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 19:44:17 volumioht sudo[4180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 19:44:17 volumioht sudo[4180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:17 volumioht sudo[4180]: pam_unix(sudo:session): session closed for user root May 31 19:44:18 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:18 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:18 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:18 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 31 19:44:18 volumioht volumio[1168]: info: CoreCommandRouter::volumioPlay May 31 19:44:18 volumioht volumio[1168]: info: CoreStateMachine::play index undefined May 31 19:44:18 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 19:44:18 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:18 volumioht volumio[1168]: info: CoreStateMachine::startPlaybackTimer May 31 19:44:18 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:18 volumioht volumio[1168]: info: [1780267458676] ControllerTidal::clearAddPlayTrack May 31 19:44:18 volumioht volumio[1168]: info: Getting stream with soundQuality LOSSLESS May 31 19:44:19 volumioht volumio[1168]: info: TidalConnect service started! May 31 19:44:20 volumioht volumio[1168]: info: TidalConnect service started! May 31 19:44:20 volumioht volumio[1168]: info: TidalConnect service started! May 31 19:44:20 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:20 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:20 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 31 19:44:20 volumioht volumio[1168]: info: CoreCommandRouter::volumioPlay May 31 19:44:20 volumioht volumio[1168]: info: CoreStateMachine::play index undefined May 31 19:44:20 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 19:44:20 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:20 volumioht volumio[1168]: info: CoreStateMachine::startPlaybackTimer May 31 19:44:20 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:20 volumioht volumio[1168]: info: [1780267460753] ControllerTidal::clearAddPlayTrack May 31 19:44:20 volumioht volumio[1168]: info: Getting stream with soundQuality LOSSLESS May 31 19:44:21 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:21 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:21 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 31 19:44:21 volumioht volumio[1168]: info: CoreCommandRouter::volumioPlay May 31 19:44:21 volumioht volumio[1168]: info: CoreStateMachine::play index undefined May 31 19:44:21 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 19:44:21 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:21 volumioht volumio[1168]: info: CoreStateMachine::startPlaybackTimer May 31 19:44:21 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:21 volumioht volumio[1168]: info: [1780267461865] ControllerTidal::clearAddPlayTrack May 31 19:44:21 volumioht volumio[1168]: info: Getting stream with soundQuality LOSSLESS May 31 19:44:22 volumioht volumio[1168]: info: getStreamUrl took 449 milliseconds May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand stop May 31 19:44:22 volumioht volumio[1168]: info: sendMpdCommand stop took 1 milliseconds May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand clear May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: info: sendMpdCommand clear took 1 milliseconds May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==" May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: error: updateQueue error: null May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 4ms May 31 19:44:22 volumioht volumio[1168]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==" took 4 milliseconds May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 3ms May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 2ms May 31 19:44:22 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand play May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:22 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 4ms May 31 19:44:22 volumioht volumio[1168]: info: sendMpdCommand play took 3 milliseconds May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 3ms May 31 19:44:22 volumioht volumio[1168]: info: ------------------------------ 2ms May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:22 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:22 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:22 volumioht volumio[1168]: info: May 31 19:44:22 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:22 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:22 volumioht volumio[1168]: info: getStreamUrl took 2094 milliseconds May 31 19:44:22 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand stop May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 757 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 861 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 860 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand stop took 360 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand clear May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:23 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 109 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 110 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 108 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 5 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 4 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 4 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand clear took 4 milliseconds May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==" May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:23 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","trackType":"tidal"} May 31 19:44:23 volumioht volumio[1168]: verbose: CURRENT POSITION 1 May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus stop May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:23 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","trackType":"tidal"} May 31 19:44:23 volumioht volumio[1168]: verbose: CURRENT POSITION 1 May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:23 volumioht volumio[1168]: info: Received an update from plugin. extracting info from payload May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:23 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"248 Kbps","isStreaming":false,"title":"0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==","trackType":"tidal"} May 31 19:44:23 volumioht volumio[1168]: verbose: CURRENT POSITION 1 May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:23 volumioht volumio[1168]: info: Received an update from plugin. extracting info from payload May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 899ms May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.289-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.290-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.293-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.293-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.297-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.297-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.301-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.302-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 1002ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 1002ms May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:23 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: error: updateQueue error: null May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:23 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 149 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 148ms May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 146 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 145 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 145 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271062~N2RkNjU5NTYwNTE2NmE4YjQxYzRlNGVkNTdjZjM2NmMxYTFkYTE5ZA==" took 145 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 11ms May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 8 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 4 milliseconds May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand play May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 1 May 31 19:44:23 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 31 19:44:23 volumioht volumio[1168]: verbose: CURRENT POSITION 1 May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService stop May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::play index undefined May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 31 19:44:23 volumioht volumio[1168]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 31 19:44:23 volumioht volumio[1168]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.456-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=170 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.456-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.461-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs= volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.461-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.464-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs= volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.469-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.469-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs= volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.470-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::startPlaybackTimer May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: [1780267463507] ControllerTidal::clearAddPlayTrack May 31 19:44:23 volumioht volumio[1168]: info: Getting stream with soundQuality LOSSLESS May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 297ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 406ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 404ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 302ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 157ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 156ms May 31 19:44:23 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:23 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:23 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:23 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.544-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=0 volume=100 May 31 19:44:23 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:23.544-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:23 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:23 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:23 volumioht sudo[4211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:23 volumioht sudo[4211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht sudo[4213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:23 volumioht sudo[4213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:23 volumioht sudo[4217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:23 volumioht sudo[4217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht sudo[4219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:23 volumioht sudo[4219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:23 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:23 volumioht sudo[4227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:23 volumioht sudo[4227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht sudo[4225]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:23 volumioht sudo[4225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 583ms May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand play took 578 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 389ms May 31 19:44:23 volumioht volumio[1168]: info: ------------------------------ 388ms May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht sudo[4229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht sudo[4229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht sudo[4221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:23 volumioht sudo[4221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht sudo[4232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:23 volumioht sudo[4232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 38 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 38 milliseconds May 31 19:44:23 volumioht volumio[1168]: info: sendMpdCommand status took 37 milliseconds May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht volumio[1168]: info: May 31 19:44:23 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:23 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:23 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:23 volumioht systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:24 volumioht sudo[4217]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht sudo[4213]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht sudo[4211]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: touch_display: Setting screensaver timeout to 0 seconds. May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 46 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 46 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 45 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 45 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 44 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 43 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 98ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 93ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 92ms May 31 19:44:24 volumioht volumio[1168]: info: touch_display: Setting screensaver timeout to 0 seconds. May 31 19:44:24 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:24 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:24 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 11 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 7 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 8 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 63ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 59ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 58ms May 31 19:44:24 volumioht sudo[4219]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: Job for peppyspectrum.service canceled. May 31 19:44:24 volumioht sudo[4227]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum failed to stop!! Error: Command failed: /usr/bin/sudo /bin/systemctl stop peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: Job for peppyspectrum.service canceled. May 31 19:44:24 volumioht sudo[4225]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum failed to stop!! Error: Command failed: /usr/bin/sudo /bin/systemctl stop peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: Job for peppyspectrum.service canceled. May 31 19:44:24 volumioht sudo[4229]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht sudo[4221]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum failed to stop!! Error: Command failed: /usr/bin/sudo /bin/systemctl stop peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: Job for peppyspectrum.service canceled. May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: Job for peppyspectrum.service canceled. May 31 19:44:24 volumioht systemd[1]: Stopping peppyspectrum.service - peppyspectrum Daemon... May 31 19:44:24 volumioht systemd[1]: peppyspectrum.service: Deactivated successfully. May 31 19:44:24 volumioht systemd[1]: Stopped peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:24 volumioht sudo[4232]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:24 volumioht volumio[1168]: info: getStreamUrl took 1121 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand stop May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand stop took 114 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand clear May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 4 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand clear took 3 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 2 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 2 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic3NmZhODBiNzFhNWFlMGEwMGU3NmEyMGY5MGM3MDg0MF82MS5tcDQ/0.flac?token=1780271064~MDg1YmJkNjQ5Njg0ODM4ODc2MTk2ODZkNmY4ZmVkZDVmZDcyNDFkYQ==" May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 19:44:24 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:24.784-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:24 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:24.785-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:24 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:24.787-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:24 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:24.788-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 56ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 55ms May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: error: updateQueue error: null May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 57ms May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 56 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic3NmZhODBiNzFhNWFlMGEwMGU3NmEyMGY5MGM3MDg0MF82MS5tcDQ/0.flac?token=1780271064~MDg1YmJkNjQ5Njg0ODM4ODc2MTk2ODZkNmY4ZmVkZDVmZDcyNDFkYQ==" took 57 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 4ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 3ms May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand play May 31 19:44:24 volumioht volumio[1168]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 64ms May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:24 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 47ms May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand play took 45 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 42ms May 31 19:44:24 volumioht volumio[1168]: info: ------------------------------ 40ms May 31 19:44:24 volumioht volumio[1168]: info: getStreamUrl took 6181 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand stop May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand stop took 3 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand clear May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:24 volumioht sudo[4244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 3 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:24 volumioht volumio[1168]: info: May 31 19:44:24 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:24 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand clear took 5 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 4 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand status took 4 milliseconds May 31 19:44:24 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 2 milliseconds May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==" May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:24 volumioht sudo[4244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:24 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht sudo[4246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht sudo[4246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 31 19:44:24 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService stop May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus stop May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: No code May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:24 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 31 19:44:24 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService stop May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus stop May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: info: No code May 31 19:44:24 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:24 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:24 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:24 volumioht volumio[1168]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 31 19:44:24 volumioht sudo[4246]: pam_unix(sudo:session): session closed for user root May 31 19:44:24 volumioht sudo[4244]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.013-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.023-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.021-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.022-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.024-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.022-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.025-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.026-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.031-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.031-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.035-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_STOPPED positionMs=1183 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.035-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084020 title="Time of Our Lives" May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 204ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 204ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 207ms May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:25 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:25 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:25 volumioht volumio[1168]: error: updateQueue error: null May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:25 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 207ms May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==" took 207 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand play May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht sudo[4251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht sudo[4256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status stop May 31 19:44:25 volumioht sudo[4258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4251]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht sudo[4267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 31 19:44:25 volumioht sudo[4267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 270ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 268ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 266ms May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand play took 262 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:25 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces system playlist update May 31 19:44:25 volumioht volumio[1168]: info: Ignoring MPD Status Update May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht sudo[4256]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht sudo[4267]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht sudo[4262]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht sudo[4258]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht sudo[4254]: pam_unix(sudo:session): session closed for user root May 31 19:44:25 volumioht volumio[1168]: info: peppyspectrum Daemon Stop May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand status took 323 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 318ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 311ms May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand status took 1 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 2 milliseconds May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:25 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:25 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","trackType":"tidal"} May 31 19:44:25 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus stop May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 328ms May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:25 volumioht volumio[1168]: info: May 31 19:44:25 volumioht volumio[1168]: ---------------------------- MPD announces state update: player May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::getState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand status May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 3 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand status took 2 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand status took 1 milliseconds May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseState May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:25 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:25 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1100,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"896 Kbps","isStreaming":false,"title":"0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","trackType":"tidal"} May 31 19:44:25 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:25 volumioht volumio[1168]: info: Received an update from plugin. extracting info from payload May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.709-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.709-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.711-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.712-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 68ms May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 61 milliseconds May 31 19:44:25 volumioht volumio[1168]: info: sendMpdCommand playlistinfo took 63 milliseconds May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:25 volumioht volumio[1168]: verbose: ControllerMpd::parseTrackInfo May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:25 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:25 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1100,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"888 Kbps","isStreaming":false,"title":"0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","trackType":"tidal"} May 31 19:44:25 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:25 volumioht volumio[1168]: info: Received an update from plugin. extracting info from payload May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio[1168]: info: ControllerMpd::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::servicePushState May 31 19:44:25 volumioht volumio[1168]: info: CorePlayQueue::getTrack 2 May 31 19:44:25 volumioht volumio[1168]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1100,"duration":214,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"888 Kbps","isStreaming":false,"title":"0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic4ODVhZTBkYTJjYzkyYTJjMzc2NjE0NjFmYTZhMzRlYl82MS5tcDQ/0.flac?token=1780271064~NjE1MWM4NGFkNzNjOTczMDVhYWY0OWU0Njg1MTY3MjI3MWQ1OWMzYQ==","trackType":"tidal"} May 31 19:44:25 volumioht volumio[1168]: verbose: CURRENT POSITION 2 May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState stateService play May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::syncState currentStatus play May 31 19:44:25 volumioht volumio[1168]: info: Received an update from plugin. extracting info from payload May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio[1168]: info: CoreStateMachine::pushState May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioPushState May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output update for this device May 31 19:44:25 volumioht volumio[1168]: info: MRS: Pushing multiroomSync output May 31 19:44:25 volumioht volumio[1168]: info: CoreCommandRouter::volumioGetState May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.793-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.794-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.796-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.797-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.798-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.799-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.801-03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" state=STATUS_PLAYING positionMs=0 volume=100 May 31 19:44:25 volumioht volumio5-onboarding[2104]: time=2026-05-31T19:44:25.801-03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.15.32:54313 @ 0x3400420" id=tidal://song/98084021 title=Summer May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 154ms May 31 19:44:25 volumioht volumio[1168]: info: ------------------------------ 154ms May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht sudo[4272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht sudo[4272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht sudo[4274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht sudo[4277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht sudo[4277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht volumio[1168]: info: PeppySpectrum ---peppyspectrum status play May 31 19:44:25 volumioht sudo[4279]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht sudo[4279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht sudo[4285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht sudo[4283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service May 31 19:44:25 volumioht sudo[4283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:25 volumioht systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:26 volumioht volumio[1168]: info: touch_display: Setting screensaver timeout to 0 seconds. May 31 19:44:26 volumioht sudo[4272]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:26 volumioht sudo[4279]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht sudo[4277]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht sudo[4283]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht sudo[4274]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht sudo[4285]: pam_unix(sudo:session): session closed for user root May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:26 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: pygame 2.1.2 (SDL 2.26.5, Python 3.11.2) May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: Hello from the pygame community. https://www.pygame.org/contribute.html May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: Traceback (most recent call last): May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrum.py", line 30, in May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: from spectrumutil import SpectrumUtil May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrumutil.py", line 19, in May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: from PIL import Image May 31 19:44:27 volumioht startpeppyspectrum.sh[4292]: ModuleNotFoundError: No module named 'PIL' May 31 19:44:27 volumioht systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE May 31 19:44:27 volumioht systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. May 31 19:44:27 volumioht systemd[1]: peppyspectrum.service: Consumed 1.367s CPU time. May 31 19:44:27 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:27 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:27 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:27 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:27 volumioht volumio[1168]: info: Executing endpoint metavolumio May 31 19:44:27 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 19:44:37 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 31 19:44:37 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 31 19:44:44 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:44:48 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum savepeppy1 [object Object] May 31 19:44:48 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy1 May 31 19:44:48 volumioht volumio[1168]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumSony May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------$basefolder/data/INTERNAL/PeppySpectrum/Templates May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------screensize1920x1080_Gelo5 Spec&Met_720 May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenwidth1920 May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenheight1080 May 31 19:44:48 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumsize30 May 31 19:44:48 volumioht volumio[1168]: error: PeppySpectrum ---Error writing config null May 31 19:44:48 volumioht sudo[4328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppyspectrum.service May 31 19:44:48 volumioht sudo[4328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:48 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:44:48 volumioht volumio[1168]: info: CoreCommandRouter::Close All Modals sent May 31 19:44:48 volumioht systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:48 volumioht sudo[4328]: pam_unix(sudo:session): session closed for user root May 31 19:44:48 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:49 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum savepeppy1 [object Object] May 31 19:44:49 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy1 May 31 19:44:49 volumioht volumio[1168]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumSony May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------$basefolder/data/INTERNAL/PeppySpectrum/Templates May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------screensize1920x1080_Gelo5 Spec&Met_720 May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenwidth1920 May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenheight1080 May 31 19:44:49 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumsize30 May 31 19:44:49 volumioht volumio[1168]: error: PeppySpectrum ---Error writing config null May 31 19:44:49 volumioht sudo[4333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppyspectrum.service May 31 19:44:49 volumioht sudo[4333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:49 volumioht systemd[1]: Stopping peppyspectrum.service - peppyspectrum Daemon... May 31 19:44:49 volumioht systemd[1]: peppyspectrum.service: Deactivated successfully. May 31 19:44:49 volumioht systemd[1]: Stopped peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:49 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:44:49 volumioht volumio[1168]: info: CoreCommandRouter::Close All Modals sent May 31 19:44:49 volumioht systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:49 volumioht sudo[4333]: pam_unix(sudo:session): session closed for user root May 31 19:44:49 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:50 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum savepeppy [object Object] May 31 19:44:50 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy May 31 19:44:50 volumioht volumio[1168]: aaaaaaaaaaa 1920,1080_Gelo5 Spec&Met_720 May 31 19:44:50 volumioht volumio[1168]: info: PeppySpectrum ---19201080_Gelo5 Spec&Met_720 May 31 19:44:50 volumioht volumio[1168]: info: PeppySpectrum ---19201080NaN May 31 19:44:50 volumioht volumio[1168]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') May 31 19:44:50 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:44:50 volumioht volumio[1168]: info: CoreCommandRouter::Close All Modals sent May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: pygame 2.1.2 (SDL 2.26.5, Python 3.11.2) May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: Hello from the pygame community. https://www.pygame.org/contribute.html May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: Traceback (most recent call last): May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrum.py", line 30, in May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: from spectrumutil import SpectrumUtil May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrumutil.py", line 19, in May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: from PIL import Image May 31 19:44:51 volumioht startpeppyspectrum.sh[4336]: ModuleNotFoundError: No module named 'PIL' May 31 19:44:51 volumioht systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE May 31 19:44:51 volumioht systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. May 31 19:44:51 volumioht systemd[1]: peppyspectrum.service: Consumed 1.533s CPU time. May 31 19:44:55 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum savepeppy1 [object Object] May 31 19:44:55 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , savepeppy1 May 31 19:44:55 volumioht volumio[1168]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then') May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumFree May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------$basefolder/data/INTERNAL/PeppySpectrum/Templates May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------screensize1920x1080_Gelo5 Spec&Met_720 May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenwidth1920 May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------screenheight1080 May 31 19:44:55 volumioht volumio[1168]: info: PeppySpectrum -----------------------spectrumsize30 May 31 19:44:55 volumioht volumio[1168]: error: PeppySpectrum ---Error writing config null May 31 19:44:55 volumioht sudo[4353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppyspectrum.service May 31 19:44:55 volumioht sudo[4353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 19:44:55 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:44:55 volumioht volumio[1168]: info: CoreCommandRouter::Close All Modals sent May 31 19:44:55 volumioht systemd[1]: Started peppyspectrum.service - peppyspectrum Daemon. May 31 19:44:55 volumioht sudo[4353]: pam_unix(sudo:session): session closed for user root May 31 19:44:55 volumioht volumio[1168]: info: peppyspectrum Daemon Started May 31 19:44:56 volumioht ntpd[1094]: PROTO: 172.233.29.160 unlink local addr 192.168.15.62 -> May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: pygame 2.1.2 (SDL 2.26.5, Python 3.11.2) May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: Hello from the pygame community. https://www.pygame.org/contribute.html May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: Traceback (most recent call last): May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrum.py", line 30, in May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: from spectrumutil import SpectrumUtil May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: File "/data/plugins/user_interface/peppyspectrum/PeppySpectrum/spectrumutil.py", line 19, in May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: from PIL import Image May 31 19:44:56 volumioht startpeppyspectrum.sh[4356]: ModuleNotFoundError: No module named 'PIL' May 31 19:44:57 volumioht systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE May 31 19:44:57 volumioht systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. May 31 19:44:57 volumioht systemd[1]: peppyspectrum.service: Consumed 1.601s CPU time. May 31 19:44:58 volumioht ntpd[1094]: PROTO: 200.160.7.196 unlink local addr 192.168.15.62 -> May 31 19:44:59 volumioht ntpd[1094]: PROTO: 200.25.72.83 unlink local addr 192.168.15.62 -> May 31 19:45:00 volumioht ntpd[1094]: PROTO: 143.107.229.210 unlink local addr 192.168.15.62 -> May 31 19:45:02 volumioht ntpd[1094]: PROTO: 168.181.126.28 unlink local addr 192.168.15.62 -> May 31 19:45:02 volumioht ntpd[1094]: PROTO: 216.238.102.201 unlink local addr 192.168.15.62 -> May 31 19:45:04 volumioht ntpd[1094]: PROTO: 143.107.229.211 unlink local addr 192.168.15.62 -> May 31 19:45:08 volumioht ntpd[1094]: PROTO: 216.238.112.29 unlink local addr 192.168.15.62 -> May 31 19:45:10 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum updatelist May 31 19:45:10 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , updatelist May 31 19:45:10 volumioht volumio[1168]: info: PeppySpectrum --- wget 'https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/spectrumslist.txt' May 31 19:45:11 volumioht ntpd[1094]: PROTO: 200.160.7.193 unlink local addr 192.168.15.62 -> May 31 19:45:11 volumioht volumio[1168]: --2026-05-31 19:45:10-- https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/spectrumslist.txt May 31 19:45:11 volumioht volumio[1168]: Resolving github.com (github.com)... 4.228.31.150 May 31 19:45:11 volumioht volumio[1168]: Connecting to github.com (github.com)|4.228.31.150|:443... connected. May 31 19:45:11 volumioht volumio[1168]: HTTP request sent, awaiting response... 302 Found May 31 19:45:11 volumioht volumio[1168]: Location: https://raw.githubusercontent.com/balbuze/Spectrum-peppyspectrum/main/spectrumslist.txt [following] May 31 19:45:11 volumioht volumio[1168]: --2026-05-31 19:45:11-- https://raw.githubusercontent.com/balbuze/Spectrum-peppyspectrum/main/spectrumslist.txt May 31 19:45:11 volumioht volumio[1168]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.109.133, 185.199.110.133, 185.199.111.133, ... May 31 19:45:11 volumioht volumio[1168]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.109.133|:443... connected. May 31 19:45:11 volumioht volumio[1168]: HTTP request sent, awaiting response... 200 OK May 31 19:45:11 volumioht volumio[1168]: Length: 471 [text/plain] May 31 19:45:11 volumioht volumio[1168]: Saving to: ‘/data/plugins/user_interface/peppyspectrum/spectrumslist.txt’ May 31 19:45:11 volumioht volumio[1168]: 0K 100% 3.06M=0s May 31 19:45:11 volumioht volumio[1168]: 2026-05-31 19:45:11 (3.06 MB/s) - ‘/data/plugins/user_interface/peppyspectrum/spectrumslist.txt’ saved [471/471] May 31 19:45:11 volumioht volumio[1168]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 19:45:11 volumioht volumio[1168]: info: CoreCommandRouter::Close All Modals sent May 31 19:45:12 volumioht ntpd[1094]: PROTO: 186.192.158.147 unlink local addr 192.168.15.62 -> May 31 19:45:13 volumioht ntpd[1094]: PROTO: 162.159.200.123 unlink local addr 192.168.15.62 -> May 31 19:45:13 volumioht volumio[1168]: info: CALLMETHOD: user_interface peppyspectrum dlspectrum [object Object] May 31 19:45:13 volumioht volumio[1168]: info: CoreCommandRouter::executeOnPlugin: peppyspectrum , dlspectrum May 31 19:45:15 volumioht volumio[1168]: --2026-05-31 19:45:13-- https://github.com/balbuze/Spectrum-peppyspectrum/raw/main/Zipped-folders/Choose May 31 19:45:15 volumioht volumio[1168]: Resolving github.com (github.com)... 4.228.31.150 May 31 19:45:15 volumioht volumio[1168]: Connecting to github.com (github.com)|4.228.31.150|:443... connected. May 31 19:45:15 volumioht volumio[1168]: HTTP request sent, awaiting response... 404 Not Found May 31 19:45:15 volumioht volumio[1168]: 2026-05-31 19:45:14 ERROR 404: Not Found. May 31 19:45:15 volumioht volumio[1168]: --2026-05-31 19:45:14-- http://a/ May 31 19:45:15 volumioht volumio[1168]: Resolving a (a)... failed: Device or resource busy. May 31 19:45:15 volumioht volumio[1168]: wget: unable to resolve host address ‘a’ May 31 19:45:15 volumioht volumio[1168]: --2026-05-31 19:45:14-- http://packet.zip/ May 31 19:45:15 volumioht volumio[1168]: Resolving packet.zip (packet.zip)... 162.255.119.167 May 31 19:45:15 volumioht volumio[1168]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected. May 31 19:45:15 volumioht volumio[1168]: HTTP request sent, awaiting response... 302 Found May 31 19:45:15 volumioht volumio[1168]: Location: http://www.packet.zip/ [following] May 31 19:45:15 volumioht volumio[1168]: --2026-05-31 19:45:15-- http://www.packet.zip/ May 31 19:45:15 volumioht volumio[1168]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19 May 31 19:45:15 volumioht volumio[1168]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected. May 31 19:45:15 volumioht volumio[1168]: HTTP request sent, awaiting response... 403 Forbidden May 31 19:45:15 volumioht volumio[1168]: 2026-05-31 19:45:15 ERROR 403: Forbidden. May 31 19:45:15 volumioht volumio[1168]: error: PeppySpectrum --- An error occurs while downloading or installing Spectrums May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove 'a': No such file or directory May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove 'packet.zip*': No such file or directory May 31 19:45:15 volumioht volumio[1168]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 19:45:15 volumioht volumio[1168]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip* May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove 'a': No such file or directory May 31 19:45:15 volumioht volumio[1168]: /bin/rm: cannot remove 'packet.zip*': No such file or directory May 31 19:45:15 volumioht volumio[1168]: at checkExecSyncError (node:child_process:887:11) May 31 19:45:15 volumioht volumio[1168]: at execSync (node:child_process:959:15) May 31 19:45:15 volumioht volumio[1168]: at /data/plugins/user_interface/peppyspectrum/index.js:770:19 May 31 19:45:15 volumioht volumio[1168]: at new Promise () May 31 19:45:15 volumioht volumio[1168]: at peppyspectrum.dlspectrum (/data/plugins/user_interface/peppyspectrum/index.js:745:12) May 31 19:45:15 volumioht volumio[1168]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) May 31 19:45:15 volumioht volumio[1168]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42) May 31 19:45:15 volumioht volumio[1168]: at Socket.emit (node:events:514:28) May 31 19:45:15 volumioht volumio[1168]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 31 19:45:15 volumioht volumio[1168]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { May 31 19:45:15 volumioht volumio[1168]: status: 1, May 31 19:45:15 volumioht volumio[1168]: signal: null, May 31 19:45:15 volumioht volumio[1168]: output: [ May 31 19:45:15 volumioht volumio[1168]: null, May 31 19:45:15 volumioht volumio[1168]: , May 31 19:45:15 volumioht volumio[1168]: May 31 19:45:15 volumioht volumio[1168]: ], May 31 19:45:15 volumioht volumio[1168]: pid: 4394, May 31 19:45:15 volumioht volumio[1168]: stdout: , May 31 19:45:15 volumioht volumio[1168]: stderr: May 31 19:45:15 volumioht volumio[1168]: } May 31 19:45:15 volumioht volumio[1168]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 19:45:16 volumioht systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 31 19:45:16 volumioht sudo[4417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-31 19:44' May 31 19:45:16 volumioht sudo[4417]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"