-- Logs begin at Sat 2025-05-03 13:42:14 EDT, end at Sun 2025-05-04 07:18:58 EDT. -- May 04 07:17:08 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:08 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:17:08 basement-volumio volumio[875]: info: Listing playlists May 04 07:17:08 basement-volumio volumio[875]: info: Listing playlists May 04 07:17:18 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:18 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:17:28 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:28 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:17:28 basement-volumio volumio[875]: info: Listing playlists May 04 07:17:38 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:38 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:17:45 basement-volumio volumiologrotate[342]: ls: cannot access '/var/log/samba/log.wb-BASEMENT': No such file or directory May 04 07:17:45 basement-volumio volumiologrotate[342]: ls: cannot access 'VOLUMIO': No such file or directory May 04 07:17:48 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:48 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:17:48 basement-volumio volumio[875]: info: Listing playlists May 04 07:17:48 basement-volumio volumio[875]: info: Listing playlists May 04 07:17:58 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:17:58 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:08 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:08 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:08 basement-volumio volumio[875]: info: Listing playlists May 04 07:18:18 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:18 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:21 basement-volumio volumio[875]: error: Upnp client error: Error: This socket has been ended by the other party May 04 07:18:23 basement-volumio volumio[875]: info: Clearing queue after UPNP request May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::ClearQueue May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::stop May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::updateTrackBlock May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrackBlock May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::stPlaybackTimer May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::serviceStop May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::serviceStop May 04 07:18:24 basement-volumio volumio[875]: info: ControllerMpd::stop May 04 07:18:24 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand stop May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::clearPlayQueue May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::saveQueue May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushQueue May 04 07:18:24 basement-volumio volumio[875]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 07:18:24 basement-volumio volumio[875]: info: May 04 07:18:24 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:24 basement-volumio volumio[875]: info: sendMpdCommand stop took 109 milliseconds May 04 07:18:24 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:24 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:24 basement-volumio volumio[875]: info: May 04 07:18:24 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:24 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:24 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:24 basement-volumio volumio[875]: info: May 04 07:18:24 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:24 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:24 basement-volumio volumio[875]: info: sendMpdCommand status took 32 milliseconds May 04 07:18:24 basement-volumio volumio[875]: info: sendMpdCommand status took 23 milliseconds May 04 07:18:24 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:24 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:24 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: 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 04 07:18:24 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService stop May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: No code May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: 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 04 07:18:24 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService stop May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: No code May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioPushState May 04 07:18:24 basement-volumio volumio[875]: info: ------------------------------ 209ms May 04 07:18:24 basement-volumio volumio[875]: info: ------------------------------ 195ms May 04 07:18:24 basement-volumio volumio[875]: info: May 04 07:18:24 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:24 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:24 basement-volumio volumio[875]: error: updateQueue error: null May 04 07:18:24 basement-volumio volumio[875]: info: ------------------------------ 199ms May 04 07:18:24 basement-volumio volumio[875]: info: ------------------------------ 21ms May 04 07:18:24 basement-volumio volumio[875]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 07:18:24 basement-volumio volumio[875]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 07:18:24 basement-volumio volumio[875]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 07:18:24 basement-volumio volumio[875]: info: Starting UPNP Playback May 04 07:18:24 basement-volumio volumio[875]: info: Preparing playback through UPNP May 04 07:18:24 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:24 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:24 basement-volumio volumio[875]: info: CoreStateMachine::setConsumeUpdateService mpd May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 21ms May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 14ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 16ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 17ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 18ms May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 10ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 15ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 17ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 18ms May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 9ms May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: May 04 07:18:25 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:25 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 49ms May 04 07:18:25 basement-volumio volumio[875]: info: ------------------------------ 43ms May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand status took 7 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 42 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:26 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:26 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Music Assistant","artist":null,"album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:26 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService play May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus stop May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 129ms May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand status took 65 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 38 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:26 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:26 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0be610b3bf724e02bcefafc192fb54a6.flac","artist":"Music Assistant","album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:26 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService play May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play May 04 07:18:26 basement-volumio volumio[875]: info: Received an update from plugin. extracting info from payload May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:26 basement-volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 189ms May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:26 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces system playlist update May 04 07:18:26 basement-volumio volumio[875]: info: Ignoring MPD Status Update May 04 07:18:26 basement-volumio volumio[875]: info: May 04 07:18:26 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 61ms May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand status took 108 milliseconds May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 104ms May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand status took 81 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 22 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:26 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:26 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":966,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"941 Kbps","isStreaming":false,"title":"0be610b3bf724e02bcefafc192fb54a6.flac","artist":"Music Assistant","album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:26 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService play May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play May 04 07:18:26 basement-volumio volumio[875]: info: Received an update from plugin. extracting info from payload May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:26 basement-volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 278ms May 04 07:18:26 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 131 milliseconds May 04 07:18:26 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:26 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:26 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:26 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1093,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"689 Kbps","isStreaming":false,"title":"0be610b3bf724e02bcefafc192fb54a6.flac","artist":"Music Assistant","album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:26 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService play May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play May 04 07:18:26 basement-volumio volumio[875]: info: Received an update from plugin. extracting info from payload May 04 07:18:26 basement-volumio volumio[875]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 04 07:18:26 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:26 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:26 basement-volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 04 07:18:26 basement-volumio volumio[875]: info: ------------------------------ 303ms May 04 07:18:28 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:28 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:28 basement-volumio volumio[875]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 04 07:18:28 basement-volumio volumio[875]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 04 07:18:28 basement-volumio volumio[875]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 04 07:18:28 basement-volumio volumio[875]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 04 07:18:28 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:28 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 04 07:18:28 basement-volumio volumio[875]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 04 07:18:28 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:28 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 04 07:18:28 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:28 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:28 basement-volumio volumio[875]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 04 07:18:28 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:28 basement-volumio volumio[875]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 04 07:18:28 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 04 07:18:28 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:28 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:29 basement-volumio volumio[875]: info: Listing playlists May 04 07:18:37 basement-volumio volumio[875]: info: May 04 07:18:37 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:37 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:37 basement-volumio volumio[875]: info: May 04 07:18:37 basement-volumio volumio[875]: ---------------------------- MPD announces state update: player May 04 07:18:37 basement-volumio volumio[875]: info: ControllerMpd::getState May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand status May 04 07:18:37 basement-volumio volumio[875]: info: sendMpdCommand status took 10 milliseconds May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:37 basement-volumio volumio[875]: info: sendMpdCommand status took 16 milliseconds May 04 07:18:37 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 9 milliseconds May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::parseState May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:37 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:37 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:37 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:37 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":11834,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"825 Kbps","isStreaming":false,"title":"0be610b3bf724e02bcefafc192fb54a6.flac","artist":"Music Assistant","album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:37 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService pause May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:37 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:37 basement-volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 04 07:18:37 basement-volumio volumio[875]: info: ------------------------------ 55ms May 04 07:18:37 basement-volumio volumio[875]: info: sendMpdCommand playlistinfo took 28 milliseconds May 04 07:18:37 basement-volumio volumio[875]: verbose: ControllerMpd::parseTrackInfo May 04 07:18:37 basement-volumio volumio[875]: info: ControllerMpd::pushState May 04 07:18:37 basement-volumio volumio[875]: info: CoreCommandRouter::servicePushState May 04 07:18:37 basement-volumio volumio[875]: verbose: In UPNP mode May 04 07:18:37 basement-volumio volumio[875]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":11834,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"825 Kbps","isStreaming":false,"title":"0be610b3bf724e02bcefafc192fb54a6.flac","artist":"Music Assistant","album":null,"uri":"http://10.6.3.208:8097/flow/Kv7s7t8v/uuid:c6e29e8d-aa7d-c82d-d82f-b827eb40469e/0be610b3bf724e02bcefafc192fb54a6.flac","trackType":"flac"} May 04 07:18:37 basement-volumio volumio[875]: verbose: CURRENT POSITION 0 May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::syncState stateService pause May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::syncState currentStatus play May 04 07:18:37 basement-volumio volumio[875]: info: CoreStateMachine::pushState May 04 07:18:37 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:37 basement-volumio volumio[875]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 04 07:18:37 basement-volumio volumio[875]: info: ------------------------------ 76ms May 04 07:18:38 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:38 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:38 basement-volumio volumio[875]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 04 07:18:38 basement-volumio volumio[875]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 04 07:18:38 basement-volumio volumio[875]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 04 07:18:38 basement-volumio volumio[875]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 04 07:18:38 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:38 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 04 07:18:38 basement-volumio volumio[875]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 04 07:18:38 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:38 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 04 07:18:38 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:38 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:38 basement-volumio volumio[875]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 04 07:18:38 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:38 basement-volumio volumio[875]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 04 07:18:38 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 04 07:18:38 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:38 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:45 basement-volumio volumiologrotate[342]: ls: cannot access '/var/log/samba/log.wb-BASEMENT': No such file or directory May 04 07:18:45 basement-volumio volumiologrotate[342]: ls: cannot access 'VOLUMIO': No such file or directory May 04 07:18:47 basement-volumio go-librespot[27029]: time="2025-05-04T07:18:47-04:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.124:4070: connect: connection timed out" May 04 07:18:47 basement-volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Error: socket hang up May 04 07:18:47 basement-volumio volumio[875]: at connResetException (internal/errors.js:607:14) May 04 07:18:47 basement-volumio volumio[875]: at Socket.socketOnEnd (_http_client.js:493:23) May 04 07:18:47 basement-volumio volumio[875]: at Socket.emit (events.js:327:22) May 04 07:18:47 basement-volumio volumio[875]: at endReadableNT (internal/streams/readable.js:1327:12) May 04 07:18:47 basement-volumio volumio[875]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 04 07:18:47 basement-volumio volumio[875]: (node:875) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 458) May 04 07:18:47 basement-volumio volumio[875]: info: Connection to go-librespot Websocket closed May 04 07:18:47 basement-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 04 07:18:47 basement-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 04 07:18:48 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:48 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:48 basement-volumio volumio[875]: An internal error occurred while serving an albumart. Details: TypeError: Cannot read property 'name' of undefined May 04 07:18:48 basement-volumio volumio[875]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 04 07:18:48 basement-volumio volumio[875]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 04 07:18:48 basement-volumio volumio[875]: at RESTApiPlayback.playbackGetState (/volumio/app/plugins/user_interface/rest_api/playback.js:262:37) May 04 07:18:48 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:48 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/route.js:137:13) May 04 07:18:48 basement-volumio volumio[875]: at Route.dispatch (/volumio/node_modules/express/lib/router/route.js:112:3) May 04 07:18:48 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:48 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:281:22 May 04 07:18:48 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:48 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:48 basement-volumio volumio[875]: at jsonParser (/volumio/node_modules/body-parser/lib/types/json.js:110:7) May 04 07:18:48 basement-volumio volumio[875]: at Layer.handle [as handle_request] (/volumio/node_modules/express/lib/router/layer.js:95:5) May 04 07:18:48 basement-volumio volumio[875]: at trim_prefix (/volumio/node_modules/express/lib/router/index.js:317:13) May 04 07:18:48 basement-volumio volumio[875]: at /volumio/node_modules/express/lib/router/index.js:284:7 May 04 07:18:48 basement-volumio volumio[875]: at Function.process_params (/volumio/node_modules/express/lib/router/index.js:335:12) May 04 07:18:48 basement-volumio volumio[875]: at next (/volumio/node_modules/express/lib/router/index.js:275:10) May 04 07:18:50 basement-volumio volumio[875]: info: Initializing connection to go-librespot Websocket May 04 07:18:50 basement-volumio volumio[875]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 04 07:18:50 basement-volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 04 07:18:50 basement-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 458. May 04 07:18:50 basement-volumio systemd[1]: Stopped go-librespot Daemon. May 04 07:18:50 basement-volumio systemd[1]: Started go-librespot Daemon. May 04 07:18:50 basement-volumio go-librespot[27429]: Librespot-go daemon starting... May 04 07:18:50 basement-volumio go-librespot[27429]: time="2025-05-04T07:18:50-04:00" level=info msg="generated new device id: 43ae5fffc5f90221c7dd3e300a55efb239a8d538" May 04 07:18:50 basement-volumio go-librespot[27429]: time="2025-05-04T07:18:50-04:00" level=debug msg="stored credentials not found" May 04 07:18:51 basement-volumio go-librespot[27429]: time="2025-05-04T07:18:51-04:00" level=debug msg="obtained new client token: AAA8pQFZW0m5Xi6cu11oFAxbbcq4G6e9YUkZ2n5yCcraZf7VLqSKpyYRkOSUGt4jy8TGCQ34gEAxZ5bFuh2k0g8+wa8UmaLoPA/PoVldiqftbvmFmTNWpzp8cqIGbi1z19qkN6mtQhzOHxd/ixF5uG3r4UIrqF4qB5AioDhCqQ8+amxo9CbklRiATLD7tBPpj8ISfwHdAfCsuq6mBVPvw2WRH3FdeEb06CKPMyVX5l9jAnCBXq6/kgG955E0Wc8=" May 04 07:18:51 basement-volumio go-librespot[27429]: time="2025-05-04T07:18:51-04: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]" May 04 07:18:51 basement-volumio volumio[875]: info: Listing playlists May 04 07:18:53 basement-volumio volumio[875]: info: Initializing connection to go-librespot Websocket May 04 07:18:53 basement-volumio go-librespot[27429]: time="2025-05-04T07:18:53-04:00" level=debug msg="new websocket client" May 04 07:18:53 basement-volumio volumio[875]: info: Connection to go-librespot Websocket established May 04 07:18:56 basement-volumio volumio[875]: info: Getting Spotify volume May 04 07:18:56 basement-volumio volumio[875]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 04 07:18:56 basement-volumio volumio[875]: info: CoreCommandRouter::volumioGetState May 04 07:18:56 basement-volumio volumio[875]: info: CorePlayQueue::getTrack 0 May 04 07:18:56 basement-volumio volumio[875]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:18:56 basement-volumio volumio[875]: TypeError: Cannot read property 'name' of undefined May 04 07:18:56 basement-volumio volumio[875]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 04 07:18:56 basement-volumio volumio[875]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 04 07:18:56 basement-volumio volumio[875]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:58:38) May 04 07:18:56 basement-volumio volumio[875]: at Socket.emit (events.js:315:20) May 04 07:18:56 basement-volumio volumio[875]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 04 07:18:56 basement-volumio volumio[875]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 04 07:18:56 basement-volumio volumio[875]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 07:18:58 basement-volumio sudo[27461]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-04 07:17 May 04 07:18:58 basement-volumio sudo[27461]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"