-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Thu 2024-05-09 17:36:17 GMT. -- May 09 17:35:00 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:01 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:02 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:03 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:04 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:04 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 17:35:04 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 17:35:04 bladelius-ask volumio[784]: info: Discovery: Getting this device information May 09 17:35:04 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:04 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 17:35:05 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:06 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:07 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:08 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:09 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:10 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:10 bladelius-ask volumio[784]: Searching plugin music_service/tidal May 09 17:35:10 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 09 17:35:11 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:11 bladelius-ask volumio[784]: info: searchTIDALUri took 1024 milliseconds May 09 17:35:11 bladelius-ask volumio[784]: info: search took 1025 milliseconds May 09 17:35:11 bladelius-ask volumio[784]: info: All search sources collected, pushing search results May 09 17:35:11 bladelius-ask volumio[784]: Searching plugin music_service/tidal May 09 17:35:11 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 09 17:35:12 bladelius-ask volumio[784]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 09 17:35:12 bladelius-ask volumio[784]: info: Received Get System Version May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 17:35:12 bladelius-ask volumio[784]: info: Received Get System Info May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 17:35:12 bladelius-ask volumio[784]: info: Discovery: Getting this device information May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 17:35:12 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:13 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:13 bladelius-ask volumio[784]: Searching plugin music_service/tidal May 09 17:35:13 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: tidal , search May 09 17:35:13 bladelius-ask volumio[784]: info: searchTIDALUri took 1328 milliseconds May 09 17:35:13 bladelius-ask volumio[784]: info: search took 1329 milliseconds May 09 17:35:13 bladelius-ask volumio[784]: info: All search sources collected, pushing search results May 09 17:35:14 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:14 bladelius-ask volumio[784]: info: searchTIDALUri took 991 milliseconds May 09 17:35:14 bladelius-ask volumio[784]: info: search took 992 milliseconds May 09 17:35:14 bladelius-ask volumio[784]: info: All search sources collected, pushing search results May 09 17:35:15 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:16 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:17 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:18 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:19 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:20 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:21 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:22 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:23 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::stPlaybackTimer May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::servicePause May 09 17:35:24 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePause May 09 17:35:24 bladelius-ask volumio[784]: info: [1715276124621] ControllerTidal::pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::setConsumeUpdateService mpd May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::pause May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand pause May 09 17:35:24 bladelius-ask volumio[784]: info: May 09 17:35:24 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand pause took 3 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:24 bladelius-ask volumio[784]: info: May 09 17:35:24 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:24 bladelius-ask volumio[784]: info: May 09 17:35:24 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand status took 6 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand status took 4 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand status took 3 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 2 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 3 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 2 milliseconds May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:24 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:24 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:24 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":119730,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"880 Kbps","isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:24 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::stPlaybackTimer May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:24 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:24 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":119730,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"880 Kbps","isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:24 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::stPlaybackTimer May 09 17:35:24 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:24 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:24 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":119730,"duration":216,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"880 Kbps","isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:24 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus pause May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:24 bladelius-ask volumio[784]: info: CoreStateMachine::stPlaybackTimer May 09 17:35:24 bladelius-ask volumio[784]: info: ------------------------------ 34ms May 09 17:35:24 bladelius-ask volumio[784]: info: ------------------------------ 33ms May 09 17:35:24 bladelius-ask volumio[784]: info: ------------------------------ 32ms May 09 17:35:25 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:26 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:27 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:28 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:29 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:30 bladelius-ask volumiologrotate[592]: ls: cannot access '/var/log/samba/log.wb-BLADELIUS': No such file or directory May 09 17:35:30 bladelius-ask volumiologrotate[592]: ls: cannot access 'ASK': No such file or directory May 09 17:35:30 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:31 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:32 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:33 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:34 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:35 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:36 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:37 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:37 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 17:35:37 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 17:35:37 bladelius-ask volumio[784]: info: Discovery: Getting this device information May 09 17:35:37 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:37 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 17:35:38 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:39 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:40 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:41 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:42 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:42 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 09 17:35:42 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 09 17:35:42 bladelius-ask volumio[784]: info: Discovery: Getting this device information May 09 17:35:42 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:42 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 09 17:35:43 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:44 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:45 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:46 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:47 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 09 17:35:48 bladelius-ask volumio[784]: info: Received Get System Version May 09 17:35:48 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 17:35:49 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:50 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:51 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:51 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 09 17:35:51 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 09 17:35:52 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:53 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:54 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioStop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::setConsumeUpdateService undefined May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::updateTrackBlock May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrackBlock May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::stPlaybackTimer May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::serviceStop May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::serviceStop May 09 17:35:55 bladelius-ask volumio[784]: info: [1715276155562] ControllerTidal::stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::setConsumeUpdateService mpd May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::stop May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand stop May 09 17:35:55 bladelius-ask volumio[784]: info: May 09 17:35:55 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand stop took 19 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:55 bladelius-ask volumio[784]: info: May 09 17:35:55 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:55 bladelius-ask volumio[784]: info: May 09 17:35:55 bladelius-ask volumio[784]: ---------------------------- MPD announces state update: player May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::getState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand status May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand status took 5 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand status took 3 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand status took 5 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 3 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 3 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseState May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:55 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:55 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: No code May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:55 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:55 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: No code May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: ------------------------------ 40ms May 09 17:35:55 bladelius-ask volumio[784]: info: ------------------------------ 38ms May 09 17:35:55 bladelius-ask volumio[784]: info: sendMpdCommand playlistinfo took 30 milliseconds May 09 17:35:55 bladelius-ask volumio[784]: verbose: ControllerMpd::parseTrackInfo May 09 17:35:55 bladelius-ask volumio[784]: info: ControllerMpd::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::servicePushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: CorePlayQueue::getTrack 3 May 09 17:35:55 bladelius-ask volumio[784]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"70479934&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/70479934&soundQuality=LOSSLESS","trackType":"tidal"} May 09 17:35:55 bladelius-ask volumio[784]: verbose: CURRENT POSITION 3 May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState stateService stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::syncState currentStatus stop May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: No code May 09 17:35:55 bladelius-ask volumio[784]: info: CoreStateMachine::pushState May 09 17:35:55 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioPushState May 09 17:35:55 bladelius-ask volumio[784]: info: ------------------------------ 51ms May 09 17:35:56 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:56 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 09 17:35:57 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:58 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:35:59 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:00 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:00 bladelius-ask volumio[784]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/bladelius/buster/armhf May 09 17:36:01 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:02 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:02 bladelius-ask volumio[784]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/bladelius/buster/armhf May 09 17:36:02 bladelius-ask volumio[784]: info: Folder /tmp/plugins removed May 09 17:36:03 bladelius-ask volumio[784]: info: Check plugin dependencies May 09 17:36:03 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 09 17:36:03 bladelius-ask volumio[784]: info: Checking if plugin already exists May 09 17:36:03 bladelius-ask volumio[784]: info: Rename folder May 09 17:36:03 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:03 bladelius-ask volumio[784]: info: Folder /tmp/downloaded_plugin.zip removed May 09 17:36:03 bladelius-ask volumio[784]: info: Move to category May 09 17:36:03 bladelius-ask volumio[784]: info: Checking if install.sh is present May 09 17:36:03 bladelius-ask volumio[784]: info: Executing install.sh May 09 17:36:03 bladelius-ask sudo[28003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh May 09 17:36:03 bladelius-ask sudo[28003]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 17:36:03 bladelius-ask volumio[784]: info: Installing Go-librespot May 09 17:36:03 bladelius-ask volumio[784]: info: Checking old vollibrespot installs May 09 17:36:03 bladelius-ask systemd[1]: Reloading. May 09 17:36:04 bladelius-ask systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 09 17:36:04 bladelius-ask systemd[1]: serial-getty@ttyS0.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 09 17:36:04 bladelius-ask systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 09 17:36:04 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:04 bladelius-ask volumio[784]: info: Dowloading daemon May 09 17:36:05 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:06 bladelius-ask volumio[784]: info: Creating Start Script May 09 17:36:06 bladelius-ask systemd[1]: Reloading. May 09 17:36:06 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:06 bladelius-ask systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 09 17:36:06 bladelius-ask sudo[28003]: pam_unix(sudo:session): session closed for user root May 09 17:36:06 bladelius-ask volumio[784]: Plugin install end detected on script May 09 17:36:06 bladelius-ask volumio[784]: info: Install script completed May 09 17:36:06 bladelius-ask volumio[784]: info: Adding reference to registry May 09 17:36:06 bladelius-ask volumio[784]: info: Done installing plugin. May 09 17:36:06 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 09 17:36:06 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 09 17:36:06 bladelius-ask volumio[784]: info: Folder /tmp/plugins removed May 09 17:36:06 bladelius-ask volumio[784]: info: Folder /tmp/downloaded_plugin.zip removed May 09 17:36:06 bladelius-ask volumio[784]: info: Folder /data/temp removed May 09 17:36:07 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:07 bladelius-ask volumio[784]: info: Enabling plugin spop May 09 17:36:07 bladelius-ask volumio[784]: info: Loading plugin "spop"... May 09 17:36:08 bladelius-ask volumio[784]: info: PLUGIN START: spop May 09 17:36:08 bladelius-ask volumio[784]: info: Creating Spotify config file May 09 17:36:08 bladelius-ask volumio[784]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 09 17:36:08 bladelius-ask volumio[784]: info: Done. May 09 17:36:08 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:08 bladelius-ask volumio[784]: info: Spotify config file written May 09 17:36:08 bladelius-ask sudo[28049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 09 17:36:08 bladelius-ask sudo[28049]: pam_unix(sudo:session): session opened for user root by (uid=0) May 09 17:36:08 bladelius-ask systemd[1]: Started go-librespot Daemon. May 09 17:36:08 bladelius-ask go-librespot[28051]: Librespot-go daemon starting... May 09 17:36:08 bladelius-ask sudo[28049]: pam_unix(sudo:session): session closed for user root May 09 17:36:08 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:08Z" level=info msg="generated new device id: 5e2e770c400961f0bb8d3cd3ecfa63716363e37f" May 09 17:36:09 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:09Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" May 09 17:36:09 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:09Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 09 17:36:09 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:09Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 09 17:36:09 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:09Z" level=debug msg="zeroconf server listening on port 36109" May 09 17:36:09 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:10 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:11 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:11 bladelius-ask volumio[784]: info: go-librespot daemon successfully initialized May 09 17:36:12 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:13 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:14 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:14 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:14Z" level=debug msg="obtained new client token: AAAoC3BKYy/YyhPJczVeMHJQLB+NnjWrkGfx6z38MtWiygjcCgK6Gf3kVJcQ6zPMwhylh0Y3BesorMltXgVauo4pVd9zTraJG0yAwumuodJRhVjkXqqmxVYyjOIN7UPXUvuYGigi1AD21sx0GN9eaMqolU9Hrz6Xsu/kI62uS307ypdWkX1c/NXwnjIlkJsxXzyo2rAtkgwpmGioNDjjGj1Q8IQL/0xfqOSXai9z1DNM+PmB7B/aa6s1xjJPBIE=" May 09 17:36:14 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:14Z" level=debug msg="completed keyexchange" May 09 17:36:14 bladelius-ask volumio[784]: info: Initializing connection to go-librespot Websocket May 09 17:36:14 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:14Z" level=debug msg="new websocket client" May 09 17:36:14 bladelius-ask volumio[784]: info: Connection to go-librespot Websocket established May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="completed challenge" May 09 17:36:15 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="authenticated as bewa42" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="authenticated as bewa42" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="dealer connection opened" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=info msg="accepted zeroconf user bewa42 from iPhone" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="received connection id: NzRiODNhYzctMjFhOC00MjNkLWI0NDctZmUyOGJhYTljZDM0K2RlYWxlcit0Y3A6Ly9nZXcxLWRlYWxlci1hLXJrdzUuZ2V3MS5zcG90aWZ5Lm5ldDo1NzAwK0U3MDIzMDRFQTY0NzJDMUQzNDNCRTM1ODQ3OTkyQjYxNEVGNUY1NDJGMzQ3QzRDMDkxRTEzQTEyNUY2NkZFNkM=" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="put connect state because NEW_DEVICE" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="handling transfer player command from 14430a9f70e043276cfb27dfe7ddc4bb189a5733" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=trace msg="fetched new page 0 with 5 items (list: 5)" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=trace msg="fetched new page 1 with 45 items (list: 50)" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="shuffled context with seed 6228207478647509242 (len: 50, keep: 34)" May 09 17:36:15 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:15Z" level=debug msg="loading track spotify:track:6AI3ezQ4o3HUoP6Dhudph3 (paused: true, position: 160111ms)" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=trace msg="emitting websocket event: will_play" May 09 17:36:16 bladelius-ask volumio[784]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6AI3ezQ4o3HUoP6Dhudph3","play_origin":"com.spotify.service.freetierartist"}} May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6AI3ezQ4o3HUoP6Dhudph3" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="requested aes key for file b4fa1ca31f003217ad2bac0964aa9c726d799211, gid: 6AI3ezQ4o3HUoP6Dhudph3" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1863" May 09 17:36:16 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1484" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched first chunk of 22, total size is 11383181 bytes" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 3/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 2/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 13/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 15/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 12/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=trace msg="seek to 160111ms (diff: 142ms, samples: 7060895, bytes: 6722800)" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 1/21, size: 524288" May 09 17:36:16 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:16Z" level=debug msg="fetched chunk 14/21, size: 524288" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=info msg="loaded track \"Not Like Us\" (uri: spotify:track:6AI3ezQ4o3HUoP6Dhudph3, paused: true, position: 160111ms, duration: 274192ms)" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=trace msg="emitting websocket event: metadata" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=trace msg="emitting websocket event: active" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="sending successful reply for delaer request" May 09 17:36:17 bladelius-ask volumio[784]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6AI3ezQ4o3HUoP6Dhudph3","name":"Not Like Us","artist_names":["Kendrick Lamar"],"album_name":"Not Like Us","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021ea0c62b2339cbf493a999ad","position":160111,"duration":274192,"release_date":"year:2024 month:5 day:4","track_number":1,"disc_number":1}} May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 09 17:36:17 bladelius-ask volumio[784]: SPOTIFY: received: {"type":"active","data":null} May 09 17:36:17 bladelius-ask volumio[784]: info: Aligning Spotify Volume to Volumio Volume May 09 17:36:17 bladelius-ask volumio[784]: info: CoreCommandRouter::volumioGetState May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=trace msg="emitting websocket event: paused" May 09 17:36:17 bladelius-ask volumio[784]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6AI3ezQ4o3HUoP6Dhudph3","play_origin":"com.spotify.service.freetierartist"}} May 09 17:36:17 bladelius-ask volumio[784]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 09 17:36:17 bladelius-ask volumio[784]: TypeError: Cannot read property 'service' of undefined May 09 17:36:17 bladelius-ask volumio[784]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) May 09 17:36:17 bladelius-ask volumio[784]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) May 09 17:36:17 bladelius-ask volumio[784]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) May 09 17:36:17 bladelius-ask volumio[784]: at WebSocket.emit (events.js:315:20) May 09 17:36:17 bladelius-ask volumio[784]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) May 09 17:36:17 bladelius-ask volumio[784]: at Receiver.emit (events.js:315:20) May 09 17:36:17 bladelius-ask volumio[784]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 May 09 17:36:17 bladelius-ask volumio[784]: at internal/process/task_queues.js:149:7 May 09 17:36:17 bladelius-ask volumio[784]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) May 09 17:36:17 bladelius-ask volumio[784]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) May 09 17:36:17 bladelius-ask volumio[784]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1867" May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 09 17:36:17 bladelius-ask go-librespot[28051]: time="2024-05-09T17:36:17Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1863" May 09 17:36:17 bladelius-ask sudo[28070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-09 17:35 May 09 17:36:17 bladelius-ask sudo[28070]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="bladelius" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 22 Feb 2024 11:40:29 AM CET" VOLUMIO_VERSION="3.605" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d3bdd0b3fc9d786f35abf7517805f755"