-- Logs begin at Sun 2024-05-12 12:13:57 MSK, end at Sun 2024-05-12 12:16:40 MSK. -- May 12 12:15:00 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 12:15:00 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 12:15:00 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 12 12:15:00 volumio volumio-remote-updater[520]: No test mode May 12 12:15:00 volumio volumio-remote-updater[520]: No alpha test mode May 12 12:15:00 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 12 12:15:00 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 12 12:15:00 volumio volumio[895]: info: CURURI: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft May 12 12:15:00 volumio volumio[895]: info: Preload queue cleared May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(03) [K2] Hold Me Close (In Der Steilwand).flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(04) [K2] I Mog Jetzt Tanzen.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(05) [K2] Gradaus.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(06) [K2] Die Nachtigall Singt.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(07) [K2] Gesprach Der Eingeborenen.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(08) [K2] Marschlied.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(09) [K2] Zillertaler Hochzeitsnacht.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(10) [K2] Horst Mi.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(11) [K2] Echo Der Frau.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(12) [K2] Keep On Dancing.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(13) [K2] Auf 'm Hausl.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(14) [K2] Dann Schau I Zum Himmel.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(15) [K2] S' Beste.flac May 12 12:15:00 volumio volumio[895]: info: Preloading song: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(16) [K2] Der Berg Ruft (Remix).flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(03) [K2] Hold Me Close (In Der Steilwand).flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(04) [K2] I Mog Jetzt Tanzen.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(05) [K2] Gradaus.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(06) [K2] Die Nachtigall Singt.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(07) [K2] Gesprach Der Eingeborenen.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(08) [K2] Marschlied.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(09) [K2] Zillertaler Hochzeitsnacht.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 12 12:15:01 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(01)%20%5BK2%5D%20Der%20Anfang.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(02)%20%5BK2%5D%20Der%20Berg%20Ruft.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(03)%20%5BK2%5D%20Hold%20Me%20Close%20(In%20Der%20Steilwand).flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(03) [K2] Hold Me Close (In Der Steilwand).flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(04)%20%5BK2%5D%20I%20Mog%20Jetzt%20Tanzen.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(04) [K2] I Mog Jetzt Tanzen.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(05)%20%5BK2%5D%20Gradaus.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(05) [K2] Gradaus.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(06)%20%5BK2%5D%20Die%20Nachtigall%20Singt.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(06) [K2] Die Nachtigall Singt.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(07)%20%5BK2%5D%20Gesprach%20Der%20Eingeborenen.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(07) [K2] Gesprach Der Eingeborenen.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(08)%20%5BK2%5D%20Marschlied.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(08) [K2] Marschlied.flac May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(09)%20%5BK2%5D%20Zillertaler%20Hochzeitsnacht.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(09) [K2] Zillertaler Hochzeitsnacht.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(10) [K2] Horst Mi.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(10)%20%5BK2%5D%20Horst%20Mi.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(10) [K2] Horst Mi.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(11) [K2] Echo Der Frau.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(11)%20%5BK2%5D%20Echo%20Der%20Frau.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(11) [K2] Echo Der Frau.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(12) [K2] Keep On Dancing.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(12)%20%5BK2%5D%20Keep%20On%20Dancing.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(12) [K2] Keep On Dancing.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(13) [K2] Auf 'm Hausl.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(13)%20%5BK2%5D%20Auf%20'm%20Hausl.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(13) [K2] Auf 'm Hausl.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(14) [K2] Dann Schau I Zum Himmel.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(14)%20%5BK2%5D%20Dann%20Schau%20I%20Zum%20Himmel.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(14) [K2] Dann Schau I Zum Himmel.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(15) [K2] S' Beste.flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(15)%20%5BK2%5D%20S'%20Beste.flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(15) [K2] S' Beste.flac May 12 12:15:01 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(16) [K2] Der Berg Ruft (Remix).flac in service mpd May 12 12:15:01 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(16)%20%5BK2%5D%20Der%20Berg%20Ruft%20(Remix).flac&metadata=false May 12 12:15:01 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(16) [K2] Der Berg Ruft (Remix).flac May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::volumioGetBrowseSources May 12 12:15:02 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 12:15:03 volumio volumio[895]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 12 12:15:03 volumio volumio[895]: info: Completed starting MyVolumio Plugin May 12 12:15:03 volumio volumio[895]: info: BOOT COMPLETED May 12 12:15:03 volumio volumio[895]: [Metrics] CommandRouter: 39s 325.72ms May 12 12:15:03 volumio volumio[895]: info: CoreCommandRouter::volumiosetStartupVolume May 12 12:15:03 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 12 12:15:03 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 12 12:15:03 volumio volumio[895]: info: CoreCommandRouter::Close All Modals sent May 12 12:15:03 volumio volumio[895]: info: CoreCommandRouter::Close All Modals sent May 12 12:15:03 volumio volumio[895]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 12:15:03 volumio volumio[895]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 12:15:03 volumio volumio[895]: info: camilladsp stopping service pid 1150... May 12 12:15:03 volumio volumio[895]: info: camilladsp service terminated, instance 1 May 12 12:15:03 volumio volumio[895]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 12:15:03 volumio volumio[895]: info: camilladsp service started and running in background, instance 1 May 12 12:15:03 volumio volumio[895]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 12:15:03 volumio volumio[895]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 12:15:03 volumio volumio[895]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 12:15:03 volumio volumio[895]: error: FusionDsp - WebSocket error: [object Object] May 12 12:15:03 volumio volumio[895]: info: camilladsp spawned new process with pid 1304, instance 1, run: true May 12 12:15:04 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 12 12:15:04 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 12 12:15:04 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 12 12:15:04 volumio volumio[895]: info: Version has changed, forcing UI Reload May 12 12:15:04 volumio volumio[895]: info: CoreCommandRouter::Reload Ui May 12 12:15:05 volumio sudo[1314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 12 12:15:05 volumio sudo[1314]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 12:15:05 volumio sudo[1314]: pam_unix(sudo:session): session closed for user root May 12 12:15:05 volumio sudo[1317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 12 12:15:05 volumio sudo[1317]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 12:15:05 volumio sudo[1317]: pam_unix(sudo:session): session closed for user root May 12 12:15:05 volumio volumio[895]: verbose: New Socket.io Connection to 192.168.1.4 from 192.168.1.6 UA: okhttp/4.9.2 Total Clients: 13 May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::volumioGetVisibleSources May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:05 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::volumioGetQueue May 12 12:15:05 volumio volumio[895]: info: CoreStateMachine::getQueue May 12 12:15:05 volumio volumio[895]: info: CorePlayQueue::getQueue May 12 12:15:05 volumio volumio[895]: info: Listing playlists May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 12 12:15:05 volumio volumio[895]: info: Received Get System Info May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:15:05 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:05 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:15:05 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:05 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:06 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 12 12:15:06 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 12 12:15:06 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 12 12:15:06 volumio volumio[895]: info: CoreCommandRouter::getUIConfigOnPlugin May 12 12:15:07 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 12:15:07 volumio volumio[895]: info: Received Get System Info May 12 12:15:07 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:15:07 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:15:07 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:15:07 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:07 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:07 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:15:08 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 12 12:15:08 volumio volumio[895]: info: camilladsp spawned new process with pid 1319, instance 1, run: true May 12 12:15:09 volumio ntpd[662]: Soliciting pool server 216.232.132.95 May 12 12:15:09 volumio ntpd[662]: Soliciting pool server 132.246.11.237 May 12 12:15:10 volumio ntpd[662]: Soliciting pool server 206.108.0.133 May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 12 12:15:10 volumio volumio[895]: info: CURURI: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft May 12 12:15:10 volumio volumio[895]: info: Preload queue cleared May 12 12:15:10 volumio ntpd[662]: Soliciting pool server 162.159.200.123 May 12 12:15:10 volumio ntpd[662]: Soliciting pool server 158.69.20.38 May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 12:15:10 volumio volumio[895]: info: Received Get System Info May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:15:10 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:10 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:10 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:15:11 volumio ntpd[662]: Soliciting pool server 207.34.48.31 May 12 12:15:11 volumio ntpd[662]: Soliciting pool server 208.81.1.244 May 12 12:15:11 volumio ntpd[662]: Soliciting pool server 162.159.200.1 May 12 12:15:11 volumio ntpd[662]: Soliciting pool server 103.144.177.88 May 12 12:15:12 volumio ntpd[662]: Soliciting pool server 2600:3c02:e000:bc::123:0 May 12 12:15:12 volumio ntpd[662]: Soliciting pool server 54.39.23.64 May 12 12:15:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 12:15:12 volumio volumio[895]: info: Received Get System Info May 12 12:15:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:15:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:15:12 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:15:12 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:12 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 12:15:13 volumio volumio[895]: info: Received Get System Info May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:15:13 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:15:13 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:15:13 volumio volumio[895]: info: Preload queue cleared May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::volumioReplaceandPlayItems May 12 12:15:13 volumio volumio[895]: info: CoreStateMachine::ClearQueue May 12 12:15:13 volumio volumio[895]: info: CoreStateMachine::stop May 12 12:15:13 volumio volumio[895]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 12:15:13 volumio volumio[895]: info: CorePlayQueue::clearPlayQueue May 12 12:15:13 volumio volumio[895]: info: CorePlayQueue::saveQueue May 12 12:15:13 volumio volumio[895]: info: CoreCommandRouter::volumioPushQueue May 12 12:15:13 volumio volumio[895]: info: CoreStateMachine::addQueueItems May 12 12:15:13 volumio volumio[895]: info: CorePlayQueue::addQueueItems May 12 12:15:13 volumio volumio[895]: info: Preload queue cleared May 12 12:15:13 volumio volumio[895]: info: Adding Item to queue: music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft May 12 12:15:13 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/K2 - Der Berg Ruft in service mpd May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(01)%20%5BK2%5D%20Der%20Anfang.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(02)%20%5BK2%5D%20Der%20Berg%20Ruft.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(03)%20%5BK2%5D%20Hold%20Me%20Close%20(In%20Der%20Steilwand).flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(03) [K2] Hold Me Close (In Der Steilwand).flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(04)%20%5BK2%5D%20I%20Mog%20Jetzt%20Tanzen.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(04) [K2] I Mog Jetzt Tanzen.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(05)%20%5BK2%5D%20Gradaus.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(05) [K2] Gradaus.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(06)%20%5BK2%5D%20Die%20Nachtigall%20Singt.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(06) [K2] Die Nachtigall Singt.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(07)%20%5BK2%5D%20Gesprach%20Der%20Eingeborenen.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(07) [K2] Gesprach Der Eingeborenen.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(08)%20%5BK2%5D%20Marschlied.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(08) [K2] Marschlied.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(09)%20%5BK2%5D%20Zillertaler%20Hochzeitsnacht.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(09) [K2] Zillertaler Hochzeitsnacht.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(10)%20%5BK2%5D%20Horst%20Mi.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(10) [K2] Horst Mi.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(11)%20%5BK2%5D%20Echo%20Der%20Frau.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(11) [K2] Echo Der Frau.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(12)%20%5BK2%5D%20Keep%20On%20Dancing.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(12) [K2] Keep On Dancing.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(13)%20%5BK2%5D%20Auf%20'm%20Hausl.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(13) [K2] Auf 'm Hausl.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(14)%20%5BK2%5D%20Dann%20Schau%20I%20Zum%20Himmel.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(14) [K2] Dann Schau I Zum Himmel.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(15)%20%5BK2%5D%20S'%20Beste.flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(15) [K2] S' Beste.flac May 12 12:15:14 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=K2/Der%20Berg%20Ruft/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FK2%20-%20Der%20Berg%20Ruft%2F(16)%20%5BK2%5D%20Der%20Berg%20Ruft%20(Remix).flac&metadata=false May 12 12:15:14 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/K2 - Der Berg Ruft/(16) [K2] Der Berg Ruft (Remix).flac May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushQueue May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::saveQueue May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::updateTrackBlock May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrackBlock May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPlay May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::play index 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::stop May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::play index undefined May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::startPlaybackTimer May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::clearAddPlayTracks NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand stop May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand stop took 3 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand clear May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand clear took 6 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand add "NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac" May 12 12:15:14 volumio volumio[895]: error: updateQueue error: null May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 6ms May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand add "NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac" took 4 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand play May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 14ms May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand play took 12 milliseconds May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 11ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 11ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 9ms May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:15:14 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 7ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 5ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 4ms May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio kernel: CIFS: __readahead_batch() returned 1/15 May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 12:15:14 volumio volumio[895]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 12:15:14 volumio volumio[895]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 12:15:14 volumio volumio[895]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 12 12:15:14 volumio volumio[895]: info: FusionDsp - ---- read samplerate from file: 44100 May 12 12:15:14 volumio volumio[895]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 31 milliseconds May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 31 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 29 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 27 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: May 12 12:15:14 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::getState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 20 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 17 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 17 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 16 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 16 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 8 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 7 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand status took 6 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus stop May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 100ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 159ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 158ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 157ms May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 110 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 107 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 106 milliseconds May 12 12:15:14 volumio volumio[895]: info: sendMpdCommand playlistinfo took 105 milliseconds May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"641 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1464,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"524 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1464,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"524 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1464,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"524 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:15:14 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:15:14 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:15:14 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:15:14 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 243ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 235ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 228ms May 12 12:15:14 volumio volumio[895]: info: ------------------------------ 226ms May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:15:14 volumio volumio[895]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 12 12:15:14 volumio volumio[895]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 12 12:15:15 volumio ntpd[662]: Soliciting pool server 158.51.134.123 May 12 12:15:15 volumio ntpd[662]: Soliciting pool server 45.33.53.84 May 12 12:15:16 volumio ntpd[662]: Soliciting pool server 72.14.183.39 May 12 12:15:17 volumio ntpd[662]: Soliciting pool server 51.81.226.229 May 12 12:16:05 volumio ntpd[662]: receive: Unexpected origin timestamp 0xe9eb0725.f2be026f does not match aorg 0000000000.00000000 from server@208.81.1.244 xmt 0xe9eb0755.4f07b9b3 May 12 12:16:05 volumio systemd[1]: Starting Daily apt download activities... May 12 12:16:05 volumio ntpd[662]: receive: Unexpected origin timestamp 0xe9eb0725.f2cd06d1 does not match aorg 0000000000.00000000 from server@207.34.48.31 xmt 0xe9eb0755.5156ac1e May 12 12:16:10 volumio systemd[1]: apt-daily.service: Succeeded. May 12 12:16:10 volumio systemd[1]: Started Daily apt download activities. May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 12 12:16:12 volumio volumio[895]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 12 12:16:12 volumio volumio[895]: info: Received Get System Version May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 12:16:12 volumio volumio[895]: info: Received Get System Info May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 12:16:12 volumio volumio[895]: info: Discovery: Getting this device information May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::volumioGetState May 12 12:16:12 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 12:16:12 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 12 12:16:12 volumio volumio[895]: info: CURURI: music-library/NAS/123/Elements/musiс/Jean Michel Jarre May 12 12:16:12 volumio volumio[895]: info: Preload queue cleared May 12 12:16:14 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 12 12:16:14 volumio volumio[895]: info: CURURI: music-library/NAS/123/Elements/musiс/Jean Michel Jarre/Albums May 12 12:16:14 volumio volumio[895]: info: Preload queue cleared May 12 12:16:15 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 12 12:16:15 volumio volumio[895]: info: CURURI: music-library/NAS/123/Elements/musiс/Jean Michel Jarre/Albums/1976 - Oxygene (Released 1983) May 12 12:16:15 volumio volumio[895]: info: Preload queue cleared May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 1 May 12 12:16:38 volumio volumio[895]: info: Prefetching next song May 12 12:16:38 volumio volumio[895]: info: DOING PREFETCH IN MPD May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand add "NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac" May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:16:38 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand add "NAS/123/Elements/musiс/K2 - Der Berg Ruft/(02) [K2] Der Berg Ruft.flac" took 2 milliseconds May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand consume 1 May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:16:38 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:16:38 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces system playlist update May 12 12:16:38 volumio volumio[895]: info: Ignoring MPD Status Update May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces state update: options May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 6ms May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand consume 1 took 5 milliseconds May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::getState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 4ms May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 4ms May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 3ms May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces state update: options May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::getState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces state update: options May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::getState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:16:38 volumio volumio[895]: info: May 12 12:16:38 volumio volumio[895]: ---------------------------- MPD announces state update: options May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::getState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand status May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand status took 5 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand status took 4 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand status took 3 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand status took 2 milliseconds May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseState May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand playlistinfo took 4 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 12:16:38 volumio volumio[895]: info: sendMpdCommand playlistinfo took 4 milliseconds May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:16:38 volumio volumio[895]: verbose: ControllerMpd::parseTrackInfo May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39078,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1067 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:16:38 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:16:38 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39078,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1067 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:16:38 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:16:38 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39078,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1067 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:16:38 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:16:38 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: ControllerMpd::pushState May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::servicePushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39078,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1067 Kbps","isStreaming":false,"title":"Der Anfang","artist":"K2","album":"Der Berg Ruft","uri":"NAS/123/Elements/musiс/K2 - Der Berg Ruft/(01) [K2] Der Anfang.flac","trackType":"flac"} May 12 12:16:38 volumio volumio[895]: verbose: CURRENT POSITION 0 May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState stateService play May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::syncState currentStatus play May 12 12:16:38 volumio volumio[895]: info: Received an update from plugin. extracting info from payload May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:38 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:38 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 109ms May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 107ms May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 107ms May 12 12:16:38 volumio volumio[895]: info: ------------------------------ 107ms May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:38 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:39 volumio volumio[895]: info: Preload queue cleared May 12 12:16:39 volumio volumio[895]: info: CoreCommandRouter::volumioReplaceandPlayItems May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::ClearQueue May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::stop May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::stPlaybackTimer May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::updateTrackBlock May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::getTrackBlock May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::pushState May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:39 volumio volumio[895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 12:16:39 volumio volumio[895]: info: CoreCommandRouter::volumioPushState May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::serviceStop May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::getTrack 0 May 12 12:16:39 volumio volumio[895]: info: CoreCommandRouter::serviceStop May 12 12:16:39 volumio volumio[895]: info: ControllerMpd::stop May 12 12:16:39 volumio volumio[895]: verbose: ControllerMpd::sendMpdCommand stop May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::clearPlayQueue May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::saveQueue May 12 12:16:39 volumio volumio[895]: info: CoreCommandRouter::volumioPushQueue May 12 12:16:39 volumio volumio[895]: info: CoreStateMachine::addQueueItems May 12 12:16:39 volumio volumio[895]: info: CorePlayQueue::addQueueItems May 12 12:16:39 volumio volumio[895]: info: Preload queue cleared May 12 12:16:39 volumio volumio[895]: info: Adding Item to queue: music-library/NAS/123/Elements/musiс/Jean Michel Jarre/Albums/1976 - Oxygene (Released 1983) May 12 12:16:39 volumio volumio[895]: info: Exploding uri music-library/NAS/123/Elements/musiс/Jean Michel Jarre/Albums/1976 - Oxygene (Released 1983) in service mpd May 12 12:16:39 volumio volumio[895]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 12 12:16:39 volumio volumio[895]: info: May 12 12:16:39 volumio volumio[895]: ---------------------------- MPD announces state update: player May 12 12:16:39 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=Jean-Michel%20Jarre/Oxygene/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FJean%20Michel%20Jarre%2FAlbums%2F1976%20-%20Oxygene%20(Released%201983)%2FJean-Michel%20Jarre%20-%20Oxygene.cue&metadata=false May 12 12:16:39 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/Jean Michel Jarre/Albums/1976 - Oxygene (Released 1983)/Jean-Michel Jarre - Oxygene.cue May 12 12:16:39 volumio volumio[895]: info: ALBUMART /albumart?cacheid=91&web=Jean-Michel%20Jarre/Oxygene/extralarge&path=%2Fmnt%2FNAS%2F123%2FElements%2Fmusi%D1%81%2FJean%20Michel%20Jarre%2FAlbums%2F1976%20-%20Oxygene%20(Released%201983)%2FJean-Michel%20Jarre%20-%20Oxygene.cue&metadata=false May 12 12:16:39 volumio volumio[895]: info: URI /mnt/NAS/123/Elements/musiс/Jean Michel Jarre/Albums/1976 - Oxygene (Released 1983)/Jean-Michel Jarre - Oxygene.cue May 12 12:16:39 volumio volumio[895]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 12:16:39 volumio volumio[895]: Error: Unable to resolve or reject the same promise twice May 12 12:16:39 volumio volumio[895]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) May 12 12:16:39 volumio volumio[895]: at /volumio/app/plugins/music_service/mpd/index.js:2568:21 May 12 12:16:39 volumio volumio[895]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) May 12 12:16:39 volumio volumio[895]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) May 12 12:16:39 volumio volumio[895]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) May 12 12:16:39 volumio volumio[895]: at Socket.emit (events.js:315:20) May 12 12:16:39 volumio volumio[895]: at addChunk (internal/streams/readable.js:309:12) May 12 12:16:39 volumio volumio[895]: at readableAddChunk (internal/streams/readable.js:280:11) May 12 12:16:39 volumio volumio[895]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 12 12:16:39 volumio volumio[895]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 12 12:16:39 volumio volumio[895]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 12:16:40 volumio sudo[1473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-12 12:15 May 12 12:16:40 volumio sudo[1473]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"