Dec 28 09:59:00 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 28 09:59:00 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 28 09:59:04 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 09:59:04 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 28 09:59:32 volumiodigi volumio[1080]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 28 09:59:35 volumiodigi volumio[1080]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/bookworm/armhf Dec 28 09:59:35 volumiodigi volumio[1080]: info: Folder /tmp/plugins removed Dec 28 09:59:36 volumiodigi volumio[1080]: info: Check plugin dependencies Dec 28 09:59:36 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 09:59:36 volumiodigi volumio[1080]: info: Checking if plugin already exists Dec 28 09:59:37 volumiodigi volumio[1080]: info: Rename folder Dec 28 09:59:37 volumiodigi volumio[1080]: info: Folder /tmp/downloaded_plugin.zip removed Dec 28 09:59:37 volumiodigi volumio[1080]: info: Move to category Dec 28 09:59:39 volumiodigi volumio[1080]: info: Checking if install.sh is present Dec 28 09:59:39 volumiodigi volumio[1080]: info: Executing install.sh Dec 28 09:59:39 volumiodigi sudo[3090]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/music_service/spop/install.sh Dec 28 09:59:39 volumiodigi sudo[3090]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 28 09:59:40 volumiodigi volumio[1080]: info: Installing Go-librespot Dec 28 09:59:40 volumiodigi volumio[1080]: info: Checking old vollibrespot installs Dec 28 09:59:40 volumiodigi systemd[1]: Reloading. Dec 28 09:59:43 volumiodigi volumio[1080]: info: Downloading daemon Dec 28 09:59:47 volumiodigi volumio[1080]: info: Creating directories Dec 28 09:59:47 volumiodigi volumio[1080]: info: Creating data directory Dec 28 09:59:47 volumiodigi volumio[1080]: info: Creating Start Script Dec 28 09:59:47 volumiodigi systemd[1]: Reloading. Dec 28 09:59:51 volumiodigi sudo[3090]: pam_unix(sudo:session): session closed for user root Dec 28 09:59:51 volumiodigi volumio[1080]: Plugin install end detected on script Dec 28 09:59:51 volumiodigi volumio[1080]: info: Install script completed Dec 28 09:59:51 volumiodigi volumio[1080]: info: Adding reference to registry Dec 28 09:59:51 volumiodigi volumio[1080]: info: Done installing plugin. Dec 28 09:59:51 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 09:59:51 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 28 09:59:51 volumiodigi volumio[1080]: info: Folder /tmp/plugins removed Dec 28 09:59:51 volumiodigi volumio[1080]: info: Folder /tmp/downloaded_plugin.zip removed Dec 28 09:59:51 volumiodigi volumio[1080]: info: Folder /data/temp removed Dec 28 09:59:57 volumiodigi volumio[1080]: info: Enabling plugin spop Dec 28 09:59:57 volumiodigi volumio[1080]: info: Loading plugin "spop"... Dec 28 10:00:01 volumiodigi volumio[1080]: info: PLUGIN START: spop Dec 28 10:00:01 volumiodigi volumio[1080]: info: Creating Spotify config file Dec 28 10:00:01 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:00:01 volumiodigi volumio[1080]: info: Done. Dec 28 10:00:01 volumiodigi volumio[1080]: info: Spotify config file written Dec 28 10:00:01 volumiodigi volumio[1080]: info: No need to fix Spotify hosts Dec 28 10:00:01 volumiodigi sudo[3195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 28 10:00:01 volumiodigi sudo[3195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 28 10:00:01 volumiodigi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 28 10:00:01 volumiodigi systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 28 10:00:01 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 28 10:00:01 volumiodigi sudo[3195]: pam_unix(sudo:session): session closed for user root Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: Dec 28 10:00:01 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:01 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:01 volumiodigi go-librespot[3197]: go-librespot daemon starting... Dec 28 10:00:03 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:03-05:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:00:03 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:03-05:00" level=debug msg="no app state found" Dec 28 10:00:03 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:03-05:00" level=debug msg="stored credentials not found" Dec 28 10:00:03 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:03-05:00" level=info msg="generated new device id: 499147be93d0eafc1ae35917517fe243f4bfd72e" Dec 28 10:00:03 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:03-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:00:04 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:04-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 28 10:00:04 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:04-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 28 10:00:04 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:04-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 28 10:00:04 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:04-05:00" level=info msg="zeroconf server listening on port 38503" Dec 28 10:00:04 volumiodigi volumio[1080]: info: sendMpdCommand status took 2442 milliseconds Dec 28 10:00:04 volumiodigi volumio[1080]: info: sendMpdCommand status took 2445 milliseconds Dec 28 10:00:04 volumiodigi volumio[1080]: info: sendMpdCommand status took 2445 milliseconds Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:04 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:04 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: No code Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:04 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: No code Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:04 volumiodigi volumio[1080]: info: ------------------------------ 3061ms Dec 28 10:00:04 volumiodigi volumio[1080]: info: ------------------------------ 3062ms Dec 28 10:00:04 volumiodigi volumio[1080]: info: go-librespot daemon successfully initialized Dec 28 10:00:04 volumiodigi volumio[1080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 28 10:00:06 volumiodigi volumio[1080]: info: sendMpdCommand status took 4413 milliseconds Dec 28 10:00:06 volumiodigi volumio[1080]: info: sendMpdCommand status took 4413 milliseconds Dec 28 10:00:06 volumiodigi volumio[1080]: info: sendMpdCommand status took 4412 milliseconds Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:06 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:06 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: No code Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:06 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: No code Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:06 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:06 volumiodigi volumio[1080]: info: ------------------------------ 4591ms Dec 28 10:00:06 volumiodigi volumio[1080]: info: ------------------------------ 4591ms Dec 28 10:00:07 volumiodigi volumio[1080]: info: sendMpdCommand status took 5806 milliseconds Dec 28 10:00:07 volumiodigi volumio[1080]: info: sendMpdCommand status took 5805 milliseconds Dec 28 10:00:07 volumiodigi volumio[1080]: info: sendMpdCommand status took 5806 milliseconds Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:07 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:07 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: No code Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:07 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: No code Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:07 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:07 volumiodigi volumio[1080]: info: ------------------------------ 6033ms Dec 28 10:00:07 volumiodigi volumio[1080]: info: ------------------------------ 6033ms Dec 28 10:00:07 volumiodigi volumio[1080]: info: Initializing connection to go-librespot Websocket Dec 28 10:00:07 volumiodigi go-librespot[3199]: time="2025-12-28T10:00:07-05:00" level=debug msg="new websocket client" Dec 28 10:00:07 volumiodigi volumio[1080]: info: Connection to go-librespot Websocket established Dec 28 10:00:10 volumiodigi volumio[1080]: info: Received OAUTH Data Dec 28 10:00:10 volumiodigi volumio[1080]: info: Executing Spotify Oauth Login Dec 28 10:00:10 volumiodigi volumio[1080]: info: Saving Spotify Refresh Token Dec 28 10:00:10 volumiodigi volumio[1080]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:00:10 volumiodigi volumio[1080]: SPOTIFY: BQCTE8qWmrVynd0evfoouUahAXv6PEzn0LzSwCYayURlYXj5wM0JHkT4VbBgRx-ZZuIVxSw4Urtvn4Y91eqAOHLgxLqg_bTPyvznkRT7v99eq1h-46XjOHduuVpom2owTtAGc_iU2Ordm8FzLXvgqtipVKD6nzpqaTEy1R5iLi9YhQdndzVIatDK2oA2gn0Qa60bqZaBxAorhO8bhXxIJ2jyzDBiIA88PpQ0zajAJQ9x3Btk5g5HfMjsox3HmOO5UFEQxNLEtsszTEyluvM-2Y_Thp3BMp0g Dec 28 10:00:10 volumiodigi volumio[1080]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:00:10 volumiodigi volumio[1080]: info: New Spotify access token = BQCTE8qWmrVynd0evfoouUahAXv6PEzn0LzSwCYayURlYXj5wM0JHkT4VbBgRx-ZZuIVxSw4Urtvn4Y91eqAOHLgxLqg_bTPyvznkRT7v99eq1h-46XjOHduuVpom2owTtAGc_iU2Ordm8FzLXvgqtipVKD6nzpqaTEy1R5iLi9YhQdndzVIatDK2oA2gn0Qa60bqZaBxAorhO8bhXxIJ2jyzDBiIA88PpQ0zajAJQ9x3Btk5g5HfMjsox3HmOO5UFEQxNLEtsszTEyluvM-2Y_Thp3BMp0g Dec 28 10:00:10 volumiodigi volumio[1080]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 28 10:00:10 volumiodigi sudo[3236]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 28 10:00:10 volumiodigi sudo[3236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 28 10:00:10 volumiodigi sudo[3236]: pam_unix(sudo:session): session closed for user root Dec 28 10:00:10 volumiodigi sudo[3238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 28 10:00:10 volumiodigi sudo[3238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 28 10:00:10 volumiodigi sudo[3238]: pam_unix(sudo:session): session closed for user root Dec 28 10:00:11 volumiodigi volumio[1080]: info: Getting Spotify volume Dec 28 10:00:11 volumiodigi volumio[1080]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 28 10:00:11 volumiodigi volumio[1080]: verbose: New Socket.io Connection to 192.168.2.124 from 192.168.2.187 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:11 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetVisibleSources Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:11 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:11 volumiodigi volumio[1080]: SPOTIFY: User informations: {"country":"US","display_name":"aahlvin","email":"aahlvin@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/aahlvin"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/aahlvin","id":"aahlvin","images":[],"product":"premium","type":"user","uri":"spotify:user:aahlvin"} Dec 28 10:00:11 volumiodigi volumio[1080]: info: Creating Spotify config file Dec 28 10:00:11 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 28 10:00:11 volumiodigi volumio[1080]: info: Spotify config file written Dec 28 10:00:11 volumiodigi sudo[3249]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 28 10:00:11 volumiodigi sudo[3249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 28 10:00:11 volumiodigi systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 28 10:00:11 volumiodigi systemd[1]: go-librespot-daemon.service: Killing process 3200 (go-librespot) with signal SIGKILL. Dec 28 10:00:11 volumiodigi systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 28 10:00:11 volumiodigi systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 28 10:00:11 volumiodigi systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 28 10:00:11 volumiodigi volumio[1080]: info: Connection to go-librespot Websocket closed Dec 28 10:00:11 volumiodigi go-librespot[3251]: go-librespot daemon starting... Dec 28 10:00:11 volumiodigi sudo[3249]: pam_unix(sudo:session): session closed for user root Dec 28 10:00:11 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:11-05:00" level=info msg="running go-librespot 0.4.0" Dec 28 10:00:11 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:11-05:00" level=debug msg="app state loaded" Dec 28 10:00:11 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:11-05:00" level=debug msg="stored credentials not found" Dec 28 10:00:11 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:11-05:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 28 10:00:11 volumiodigi volumio[1080]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:00:11 volumiodigi volumio[1080]: SPOTIFY: BQBH6bcHYRh6d2GA5SlGlpMdsoQ7-USANJqx0y932JVgoTpr6dvPqxSfYrMEsvK8FL3rHI0Mxqebwq-eD1crk9xp1-pJeYpFB28sW45kvXJ0NKC1XxebVG8Qovzs18_3KpmgduxFD-CZzYrrh1OSvaEPxDKKAaYF1aDKF_Opkiyp5pzqEZMfi1flfCT6A0HmV35Cwa9Rhk7n_qNJLy2AK6feAjFnLBq0pivIADMD1HE0F5GueGKnJ4fmF62gSSUHa9dNlJ0DSlkTPb0UF3pef7fpf1d4nPmV Dec 28 10:00:11 volumiodigi volumio[1080]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 28 10:00:11 volumiodigi volumio[1080]: info: New Spotify access token = BQBH6bcHYRh6d2GA5SlGlpMdsoQ7-USANJqx0y932JVgoTpr6dvPqxSfYrMEsvK8FL3rHI0Mxqebwq-eD1crk9xp1-pJeYpFB28sW45kvXJ0NKC1XxebVG8Qovzs18_3KpmgduxFD-CZzYrrh1OSvaEPxDKKAaYF1aDKF_Opkiyp5pzqEZMfi1flfCT6A0HmV35Cwa9Rhk7n_qNJLy2AK6feAjFnLBq0pivIADMD1HE0F5GueGKnJ4fmF62gSSUHa9dNlJ0DSlkTPb0UF3pef7fpf1d4nPmV Dec 28 10:00:11 volumiodigi volumio[1080]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 28 10:00:12 volumiodigi volumio[1080]: SPOTIFY: User informations: {"country":"US","display_name":"aahlvin","email":"aahlvin@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/aahlvin"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/aahlvin","id":"aahlvin","images":[],"product":"premium","type":"user","uri":"spotify:user:aahlvin"} Dec 28 10:00:12 volumiodigi volumio[1080]: info: Spotify Successfully logged in Dec 28 10:00:12 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 28 10:00:12 volumiodigi volumio[1080]: info: [1766934012147] CoreMusicLibrary::Adding element Spotify Dec 28 10:00:12 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 28 10:00:12 volumiodigi volumio[1080]: Cannot find translation for source Spotify Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=info msg="zeroconf server listening on port 45321" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="obtained new client token: AAA840c3oeqeYIQSY6kYVzNKjAxE+pcHtBELrEitc54rYqltE70CVmrNw89sT66blbD13uGCqank1pWIFc6pLWYnBErLuIEaGz5Xfx2vd8RcaqbkgMjy3U7ihNLNL2m3tQDiAAByDjyVPr0kEcNwW0YRPXOrGZv7Fp2zhziNgqkVz1KvLHXZrTEq0vIYj5xy+xGq8tiLMxAja/RjQzFWKtwvMyGmNT9L9gLoenRPpJBh73miUJ5a/kynJQ==" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="completed keyexchange" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=debug msg="completed challenge" Dec 28 10:00:12 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:12-05:00" level=info msg="authenticated AP" username="aa***in" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=info msg="authenticated Login5" username="aa***in" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="stored credentials" username="aa***in" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="initializing zeroconf session" username="aa***in" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="dealer connection opened" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=trace msg="starting accesspoint recv loop" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=trace msg="starting dealer recv loop" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=trace msg="received accesspoint ping" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="received connection id: MWRiYTVlYzUtMzUx...MThEOUM4N0JFNQ==" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=trace msg="received accesspoint pong ack" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="put connect state because NEW_DEVICE" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="update volume requested to 65535/65535" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=debug msg="put connect state because VOLUME_CHANGED" Dec 28 10:00:13 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:13-05:00" level=trace msg="emitting websocket event: volume" Dec 28 10:00:13 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 28 10:00:13 volumiodigi volumio[1080]: info: Received Get System Info Dec 28 10:00:13 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:00:13 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:00:13 volumiodigi volumio[1080]: info: Discovery: Getting this device information Dec 28 10:00:13 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:13 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:13 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:00:14 volumiodigi volumio[1080]: info: Initializing connection to go-librespot Websocket Dec 28 10:00:14 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:14-05:00" level=debug msg="new websocket client" Dec 28 10:00:14 volumiodigi volumio[1080]: info: Connection to go-librespot Websocket established Dec 28 10:00:14 volumiodigi volumio[1080]: info: go-librespot daemon successfully initialized Dec 28 10:00:17 volumiodigi volumio[1080]: info: Getting Spotify volume Dec 28 10:00:17 volumiodigi volumio[1080]: info: Initializing connection to go-librespot Websocket Dec 28 10:00:17 volumiodigi volumio[1080]: info: Spotify volume: 100 Dec 28 10:00:17 volumiodigi volumio[1080]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 28 10:00:17 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:17-05:00" level=debug msg="new websocket client" Dec 28 10:00:17 volumiodigi volumio[1080]: info: Connection to go-librespot Websocket established Dec 28 10:00:18 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:18 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:20 volumiodigi volumio[1080]: info: Getting Spotify volume Dec 28 10:00:20 volumiodigi volumio[1080]: info: Spotify volume: 100 Dec 28 10:00:21 volumiodigi volumio[1080]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 28 10:00:21 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:21 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:25 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: MPD Database updated - AlbumList cache refreshed Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: database Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: Dec 28 10:00:25 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:25 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:25 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:28 volumiodigi volumio[1080]: info: sendMpdCommand status took 2575 milliseconds Dec 28 10:00:28 volumiodigi volumio[1080]: info: sendMpdCommand status took 2574 milliseconds Dec 28 10:00:28 volumiodigi volumio[1080]: info: sendMpdCommand status took 2574 milliseconds Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:28 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:28 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: No code Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:28 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: No code Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:28 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:28 volumiodigi volumio[1080]: info: ------------------------------ 2786ms Dec 28 10:00:28 volumiodigi volumio[1080]: info: ------------------------------ 2786ms Dec 28 10:00:30 volumiodigi volumio[1080]: info: sendMpdCommand status took 4372 milliseconds Dec 28 10:00:30 volumiodigi volumio[1080]: info: sendMpdCommand status took 4381 milliseconds Dec 28 10:00:30 volumiodigi volumio[1080]: info: sendMpdCommand status took 4380 milliseconds Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:30 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:30 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: No code Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:30 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: No code Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:30 volumiodigi volumio[1080]: info: ------------------------------ 4570ms Dec 28 10:00:30 volumiodigi volumio[1080]: info: ------------------------------ 4572ms Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 28 10:00:30 volumiodigi volumio[1080]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 28 10:00:30 volumiodigi volumio[1080]: info: Received Get System Version Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:00:30 volumiodigi volumio[1080]: info: Received Get System Info Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 28 10:00:30 volumiodigi volumio[1080]: info: Discovery: Getting this device information Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetState Dec 28 10:00:30 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:30 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 28 10:00:31 volumiodigi volumio[1080]: info: sendMpdCommand status took 5998 milliseconds Dec 28 10:00:31 volumiodigi volumio[1080]: info: sendMpdCommand status took 6000 milliseconds Dec 28 10:00:31 volumiodigi volumio[1080]: info: sendMpdCommand status took 6000 milliseconds Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:31 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatetrue Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:31 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: No code Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 28 10:00:31 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: No code Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:31 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:31 volumiodigi volumio[1080]: info: ------------------------------ 6202ms Dec 28 10:00:31 volumiodigi volumio[1080]: info: ------------------------------ 6203ms Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: info: Dec 28 10:00:32 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:32 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: info: Dec 28 10:00:32 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:32 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: info: Dec 28 10:00:32 volumiodigi volumio[1080]: ---------------------------- MPD announces state update: update Dec 28 10:00:32 volumiodigi volumio[1080]: info: ControllerMpd::getState Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::sendMpdCommand status Dec 28 10:00:32 volumiodigi volumio[1080]: info: sendMpdCommand status took 10 milliseconds Dec 28 10:00:32 volumiodigi volumio[1080]: info: sendMpdCommand status took 8 milliseconds Dec 28 10:00:32 volumiodigi volumio[1080]: info: sendMpdCommand status took 7 milliseconds Dec 28 10:00:32 volumiodigi volumio[1080]: info: sendMpdCommand status took 6 milliseconds Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:32 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatefalse Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:32 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatefalse Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:32 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: 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} Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: No code Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: 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} Dec 28 10:00:32 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: No code Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:32 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:32 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: ------------------------------ 203ms Dec 28 10:00:33 volumiodigi volumio[1080]: info: ------------------------------ 200ms Dec 28 10:00:33 volumiodigi volumio[1080]: info: sendMpdCommand status took 208 milliseconds Dec 28 10:00:33 volumiodigi volumio[1080]: info: sendMpdCommand status took 206 milliseconds Dec 28 10:00:33 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:33 volumiodigi volumio[1080]: info: Command Router : Notfying DB Updatefalse Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreCommandRouter::Close All Modals sent Dec 28 10:00:33 volumiodigi volumio[1080]: verbose: ControllerMpd::parseState Dec 28 10:00:33 volumiodigi volumio[1080]: info: ControllerMpd::pushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreCommandRouter::servicePushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:33 volumiodigi volumio[1080]: 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} Dec 28 10:00:33 volumiodigi volumio[1080]: verbose: CURRENT POSITION 0 Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreStateMachine::syncState stateService stop Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreStateMachine::syncState currentStatus stop Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: No code Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreStateMachine::pushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: CorePlayQueue::getTrack 0 Dec 28 10:00:33 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioPushState Dec 28 10:00:33 volumiodigi volumio[1080]: info: ------------------------------ 304ms Dec 28 10:00:34 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 28 10:00:34 volumiodigi volumio[1080]: info: CURURI: artists:// Dec 28 10:00:34 volumiodigi volumio[1080]: info: CoreCommandRouter::volumioGetQueue Dec 28 10:00:34 volumiodigi volumio[1080]: info: CoreStateMachine::getQueue Dec 28 10:00:34 volumiodigi volumio[1080]: info: CorePlayQueue::getQueue Dec 28 10:00:34 volumiodigi volumio[1080]: info: Listing playlists Dec 28 10:00:34 volumiodigi volumio[1080]: info: Preload queue cleared Dec 28 10:00:41 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Dec 28 10:00:41 volumiodigi volumio[1080]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 28 10:00:41 volumiodigi volumio[1080]: info: Preload queue cleared Dec 28 10:00:43 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:43-05:00" level=trace msg="sent dealer ping" Dec 28 10:00:43 volumiodigi go-librespot[3252]: time="2025-12-28T10:00:43-05:00" level=trace msg="received dealer pong" Dec 28 10:00:55 volumiodigi volumio[1080]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:00:55 volumiodigi volumio[1080]: TypeError: Cannot read properties of null (reading 'slice') Dec 28 10:00:55 volumiodigi volumio[1080]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Dec 28 10:00:55 volumiodigi volumio[1080]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Dec 28 10:00:55 volumiodigi volumio[1080]: at Object.onceWrapper (node:events:629:26) Dec 28 10:00:55 volumiodigi volumio[1080]: at ClientRequest.emit (node:events:514:28) Dec 28 10:00:55 volumiodigi volumio[1080]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Dec 28 10:00:55 volumiodigi volumio[1080]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Dec 28 10:00:55 volumiodigi volumio[1080]: at TLSSocket.socketOnData (node:_http_client:535:22) Dec 28 10:00:55 volumiodigi volumio[1080]: at TLSSocket.emit (node:events:514:28) Dec 28 10:00:55 volumiodigi volumio[1080]: at addChunk (node:internal/streams/readable:343:12) Dec 28 10:00:55 volumiodigi volumio[1080]: at readableAddChunk (node:internal/streams/readable:316:9) Dec 28 10:00:55 volumiodigi volumio[1080]: at Readable.push (node:internal/streams/readable:253:10) Dec 28 10:00:55 volumiodigi volumio[1080]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Dec 28 10:00:55 volumiodigi volumio[1080]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 28 10:00:57 volumiodigi sudo[3399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-28 09:59' Dec 28 10:00:57 volumiodigi sudo[3399]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"