-- Logs begin at Thu 2019-02-14 15:42:00 IST, end at Wed 2025-04-16 19:07:43 IST. --
Apr 16 19:06:08 volumio sudo[2086]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 16 19:06:08 volumio sudo[2086]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 16 19:06:08 volumio sudo[2086]: pam_unix(sudo:session): session closed for user root
Apr 16 19:06:08 volumio sudo[2088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 16 19:06:08 volumio sudo[2088]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 16 19:06:08 volumio sudo[2088]: pam_unix(sudo:session): session closed for user root
Apr 16 19:06:08 volumio volumio[974]: verbose: New Socket.io Connection to 192.168.1.7 from 192.168.1.8 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::volumioGetState
Apr 16 19:06:08 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 16 19:06:08 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 16 19:06:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 16 19:06:10 volumio volumio[974]: info: Received Get System Info
Apr 16 19:06:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 16 19:06:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 16 19:06:10 volumio volumio[974]: info: Discovery: Getting this device information
Apr 16 19:06:10 volumio volumio[974]: info: CoreCommandRouter::volumioGetState
Apr 16 19:06:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 16 19:06:11 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 16 19:06:11 volumio go-librespot[2027]: time="2025-04-16T19:06:11+05:30" level=trace msg="sent dealer ping"
Apr 16 19:06:11 volumio volumio[974]: info: Received Get System Info
Apr 16 19:06:11 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 16 19:06:11 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 16 19:06:11 volumio volumio[974]: info: Discovery: Getting this device information
Apr 16 19:06:11 volumio volumio[974]: info: CoreCommandRouter::volumioGetState
Apr 16 19:06:11 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:11 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 16 19:06:11 volumio go-librespot[2027]: time="2025-04-16T19:06:11+05:30" level=trace msg="received dealer pong"
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: info: Retrieving Cloud Streaming UI
Apr 16 19:06:18 volumio volumio[974]: info: Getting Tidal Cloud Configuration
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: info: Getting Qobuz Cloud Configuration
Apr 16 19:06:18 volumio volumio[974]: info: Asking plugin for UI Config
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: info: Getting Spotify Cloud Configuration
Apr 16 19:06:18 volumio volumio[974]: info: Asking plugin for UI Config
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: info: Saving Spotify Acccount
Apr 16 19:06:18 volumio volumio[974]: info: Got Tidal Cloud Configuration
Apr 16 19:06:18 volumio volumio[974]: info: Got it
Apr 16 19:06:18 volumio volumio[974]: info: Got it
Apr 16 19:06:18 volumio volumio[974]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 16 19:06:18 volumio volumio[974]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetBrowseSources
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand update
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand update took 12 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 24 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 16 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 16 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 14 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 13 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 12 milliseconds
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatetrue
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:20 volumio volumio[974]: info: ------------------------------ 288ms
Apr 16 19:06:20 volumio volumio[974]: info: ------------------------------ 280ms
Apr 16 19:06:20 volumio volumio[974]: info: ------------------------------ 277ms
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info:
Apr 16 19:06:20 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 286 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 280 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 13 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 11 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 10 milliseconds
Apr 16 19:06:20 volumio volumio[974]: info: sendMpdCommand status took 8 milliseconds
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:20 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:20 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:20 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:20 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:20 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 538ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 266ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 264ms
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand update
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand update took 49 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 18 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 15 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 14 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 11 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 11 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 9 milliseconds
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 259ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 255ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 252ms
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info:
Apr 16 19:06:21 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 262 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 259 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 13 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 11 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 9 milliseconds
Apr 16 19:06:21 volumio volumio[974]: info: sendMpdCommand status took 7 milliseconds
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:06:21 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:06:21 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:06:21 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:21 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 510ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 262ms
Apr 16 19:06:21 volumio volumio[974]: info: ------------------------------ 258ms
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:21 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:06:22 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 16 19:06:26 volumio volumio[974]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Apr 16 19:06:26 volumio volumio[974]: info: Received Get System Version
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 16 19:06:26 volumio volumio[974]: info: Received Get System Info
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 16 19:06:26 volumio volumio[974]: info: Discovery: Getting this device information
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::volumioGetState
Apr 16 19:06:26 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:06:26 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 16 19:06:28 volumio volumio[974]: info: Enabling MyMusic plugin bluetooth
Apr 16 19:06:28 volumio volumio[974]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth
Apr 16 19:06:28 volumio volumio[974]: info: [MyVolumio PluginManager] Plugin audio_interface bluetooth not in user plan, not enabling
Apr 16 19:06:28 volumio volumio[974]: info: Error: Plugin audio_interface bluetooth not in user plan, not enabling
Apr 16 19:06:28 volumio volumio[974]: error: Could not Enable MyMusic Plugin: Error
Apr 16 19:06:30 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:34 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:39 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:41 volumio go-librespot[2027]: time="2025-04-16T19:06:41+05:30" level=trace msg="sent dealer ping"
Apr 16 19:06:41 volumio go-librespot[2027]: time="2025-04-16T19:06:41+05:30" level=trace msg="received dealer pong"
Apr 16 19:06:42 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:46 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:50 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:54 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:06:58 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:07:02 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:07:06 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand rescan
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand rescan took 12 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 17 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 15 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 14 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 12 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 11 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 10 milliseconds
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 268ms
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 265ms
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 262ms
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info:
Apr 16 19:07:10 volumio volumio[974]: ---------------------------- MPD announces state update: update
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::getState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 270 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 268 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 12 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 10 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 9 milliseconds
Apr 16 19:07:10 volumio volumio[974]: info: sendMpdCommand status took 8 milliseconds
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: Command Router : Notfying DB Updatefalse
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent
Apr 16 19:07:10 volumio volumio[974]: verbose: ControllerMpd::parseState
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ControllerMpd::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::servicePushState
Apr 16 19:07:10 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:10 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:10 volumio volumio[974]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 508ms
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 250ms
Apr 16 19:07:10 volumio volumio[974]: info: ------------------------------ 247ms
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:11 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:07:11 volumio go-librespot[2027]: time="2025-04-16T19:07:11+05:30" level=trace msg="sent dealer ping"
Apr 16 19:07:11 volumio go-librespot[2027]: time="2025-04-16T19:07:11+05:30" level=trace msg="received dealer pong"
Apr 16 19:07:14 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Apr 16 19:07:16 volumio volumio[974]: info: CoreCommandRouter::volumioGetQueue
Apr 16 19:07:16 volumio volumio[974]: info: CoreStateMachine::getQueue
Apr 16 19:07:16 volumio volumio[974]: info: CorePlayQueue::getQueue
Apr 16 19:07:16 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:17 volumio volumio[974]: info: Listing playlists
Apr 16 19:07:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:18 volumio volumio[974]: info: CURURI: playlists
Apr 16 19:07:18 volumio volumio[974]: info: Listing playlists
Apr 16 19:07:18 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:18 volumio volumio[974]: info: CURURI: music-library
Apr 16 19:07:18 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:19 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:19 volumio volumio[974]: info: CURURI: artists://
Apr 16 19:07:19 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:20 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:20 volumio volumio[974]: info: CURURI: music-library
Apr 16 19:07:20 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:21 volumio volumio[974]: info: CURURI: music-library/USB
Apr 16 19:07:21 volumio volumio[974]: error: Failed LSINFO: null
Apr 16 19:07:21 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:25 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:25 volumio volumio[974]: info: CURURI: albums://
Apr 16 19:07:25 volumio volumio[974]: info: listAlbums - loading Albums from cache
Apr 16 19:07:25 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:27 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 16 19:07:27 volumio volumio[974]: info: CURURI: genres://
Apr 16 19:07:27 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:28 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 16 19:07:28 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:31 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 16 19:07:31 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:35 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::volumioReplaceandPlayItems
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::ClearQueue
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::stop
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::stPlaybackTimer
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::updateTrackBlock
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::getTrackBlock
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::pushState
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::volumioPushState
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::serviceStop
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::getTrack 320
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::serviceStop
Apr 16 19:07:35 volumio volumio[974]: info: Spotify Stop
Apr 16 19:07:35 volumio volumio[974]: SPOTIFY: SPOTIFY STOP
Apr 16 19:07:35 volumio volumio[974]: SPOTIFY: {"status":"play","position":320,"title":"Khwaja Endan Khwaja","artist":"A.R. Rahman","album":"Jodhaa Akbar (Tamil) [Original Motion Picture Soundtrack]","albumart":"https://i.scdn.co/image/ab67616d0000b273839f66b22f0727830b4579bc","uri":"spotify:track:5B4m5El0IMiLzv6cvWJd8J","trackType":"spotify","codec":"ogg","seek":260367,"duration":416,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"}
Apr 16 19:07:35 volumio volumio[974]: info: Sending Spotify command to local API: /player/pause
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::clearPlayQueue
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::saveQueue
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::volumioPushQueue
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::addQueueItems
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::addQueueItems
Apr 16 19:07:35 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:35 volumio volumio[974]: info: Adding Item to queue: upnp/folder/http://192.168.1.7:8200/ctl/ContentDir@1
Apr 16 19:07:35 volumio volumio[974]: info: Exploding uri upnp/folder/http://192.168.1.7:8200/ctl/ContentDir@1 in service upnp_browser
Apr 16 19:07:35 volumio volumio[974]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::volumioPushQueue
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::saveQueue
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::updateTrackBlock
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::getTrackBlock
Apr 16 19:07:35 volumio volumio[974]: info: CoreCommandRouter::volumioPlay
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::play index 0
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::stop
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::play index undefined
Apr 16 19:07:35 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 16 19:07:35 volumio volumio[974]: info: CorePlayQueue::getTrack 0
Apr 16 19:07:38 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 16 19:07:39 volumio volumio[974]: info: Preload queue cleared
Apr 16 19:07:40 volumio go-librespot[2027]: time="2025-04-16T19:07:40+05:30" level=trace msg="received accesspoint ping"
Apr 16 19:07:41 volumio go-librespot[2027]: time="2025-04-16T19:07:41+05:30" level=trace msg="received accesspoint pong ack"
Apr 16 19:07:41 volumio go-librespot[2027]: time="2025-04-16T19:07:41+05:30" level=trace msg="sent dealer ping"
Apr 16 19:07:41 volumio go-librespot[2027]: time="2025-04-16T19:07:41+05:30" level=trace msg="received dealer pong"
Apr 16 19:07:42 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Apr 16 19:07:42 volumio volumio[974]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 16 19:07:42 volumio volumio[974]: TypeError: Cannot read property 'length' of undefined
Apr 16 19:07:42 volumio volumio[974]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25
Apr 16 19:07:42 volumio volumio[974]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13
Apr 16 19:07:42 volumio volumio[974]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18)
Apr 16 19:07:42 volumio volumio[974]: at Parser.emit (events.js:315:20)
Apr 16 19:07:42 volumio volumio[974]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26)
Apr 16 19:07:42 volumio volumio[974]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35)
Apr 16 19:07:42 volumio volumio[974]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5)
Apr 16 19:07:42 volumio volumio[974]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7)
Apr 16 19:07:42 volumio volumio[974]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13)
Apr 16 19:07:42 volumio volumio[974]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31)
Apr 16 19:07:42 volumio volumio[974]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59)
Apr 16 19:07:42 volumio volumio[974]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19)
Apr 16 19:07:42 volumio volumio[974]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15)
Apr 16 19:07:42 volumio volumio[974]: at IncomingMessage.emit (events.js:327:22)
Apr 16 19:07:42 volumio volumio[974]: at endReadableNT (internal/streams/readable.js:1327:12)
Apr 16 19:07:42 volumio volumio[974]: at processTicksAndRejections (internal/process/task_queues.js:80:21)
Apr 16 19:07:42 volumio volumio[974]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 16 19:07:43 volumio sudo[2366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-16 19:06
Apr 16 19:07:43 volumio sudo[2366]: 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="147953990fca4aa103a8f90538ef56fb0454638c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST"
VOLUMIO_VERSION="3.799"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"