-- Logs begin at Sun 2025-11-02 11:31:22 -03, end at Sun 2025-11-02 11:34:41 -03. -- Nov 02 11:33:01 volumio volumio[745]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 02 11:33:01 volumio volumio[745]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 02 11:33:01 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:01 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:01 volumio volumio[745]: info: Starting MyVolumio Remote Streaming Endpoints Nov 02 11:33:01 volumio volumio[745]: info: MyVolumio login type: Token Nov 02 11:33:01 volumio volumio[745]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 02 11:33:01 volumio volumio[745]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 02 11:33:02 volumio ntpd[705]: Soliciting pool server 200.160.7.193 Nov 02 11:33:03 volumio ntpd[705]: Soliciting pool server 194.58.38.95 Nov 02 11:33:03 volumio ntpd[705]: Soliciting pool server 200.160.0.8 Nov 02 11:33:03 volumio ntpd[705]: Soliciting pool server 162.159.200.123 Nov 02 11:33:04 volumio ntpd[705]: Soliciting pool server 200.160.7.186 Nov 02 11:33:04 volumio ntpd[705]: Soliciting pool server 168.181.126.28 Nov 02 11:33:04 volumio ntpd[705]: Soliciting pool server 200.189.40.8 Nov 02 11:33:04 volumio volumio[745]: info: Starting Streaming Service Transparent Proxy Nov 02 11:33:04 volumio volumio[745]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 02 11:33:04 volumio volumio[745]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 02 11:33:04 volumio volumio[745]: info: Streaming services startup Nov 02 11:33:04 volumio volumio[745]: info: Starting Streaming Daemon Nov 02 11:33:04 volumio volumio[745]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 02 11:33:04 volumio sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 11:33:04 volumio sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 11:33:04 volumio volumio[745]: SPOTIFY: SETTING SPOTIFY VOLUME 95 Nov 02 11:33:04 volumio volumio[745]: info: Sending Spotify command with payload to local API: /player/volume Nov 02 11:33:04 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:33:04 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:33:04 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:04 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:04 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:33:04 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:04 volumio volumio[745]: info: [1762093984914] ControllerWebradio::clearAddPlayTrack Nov 02 11:33:04 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:33:04 volumio sudo[1261]: pam_unix(sudo:session): session closed for user root Nov 02 11:33:04 volumio volumio[745]: info: sendMpdCommand stop took 52 milliseconds Nov 02 11:33:04 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 11:33:04 volumio volumio[745]: error: Cannot start Volumio Streaming Daemon Nov 02 11:33:04 volumio volumio[745]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 11:33:04 volumio volumio[745]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 11:33:04 volumio volumio[745]: info: Nov 02 11:33:04 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:04 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:04 volumio volumio[745]: info: sendMpdCommand clear took 17 milliseconds Nov 02 11:33:04 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand load "http://88.208.244.107:8002/stream" Nov 02 11:33:05 volumio volumio[745]: info: Nov 02 11:33:05 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:05 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:05 volumio volumio[745]: info: Nov 02 11:33:05 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:05 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:05 volumio volumio[745]: error: updateQueue error: null Nov 02 11:33:05 volumio volumio[745]: info: ------------------------------ 27ms Nov 02 11:33:05 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:33:05 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:33:05 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:33:05 volumio ntpd[705]: Soliciting pool server 192.36.143.130 Nov 02 11:33:05 volumio ntpd[705]: Soliciting pool server 200.192.232.8 Nov 02 11:33:05 volumio ntpd[705]: Soliciting pool server 200.160.7.196 Nov 02 11:33:05 volumio volumio[745]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 02 11:33:06 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand add "http://88.208.244.107:8002/stream" Nov 02 11:33:06 volumio volumio[745]: error: updateQueue error: null Nov 02 11:33:06 volumio volumio[745]: error: updateQueue error: null Nov 02 11:33:06 volumio volumio[745]: info: Nov 02 11:33:06 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:06 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:06 volumio volumio[745]: info: ------------------------------ 1038ms Nov 02 11:33:06 volumio volumio[745]: info: ------------------------------ 1034ms Nov 02 11:33:06 volumio volumio[745]: info: sendMpdCommand add "http://88.208.244.107:8002/stream" took 7 milliseconds Nov 02 11:33:06 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 02 11:33:06 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand play Nov 02 11:33:06 volumio volumio[745]: info: Nov 02 11:33:06 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:06 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:06 volumio volumio[745]: info: Nov 02 11:33:06 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:06 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:06 volumio volumio[745]: info: ------------------------------ 28ms Nov 02 11:33:06 volumio volumio[745]: info: sendMpdCommand play took 23 milliseconds Nov 02 11:33:06 volumio volumio[745]: info: ------------------------------ 19ms Nov 02 11:33:06 volumio volumio[745]: info: ------------------------------ 16ms Nov 02 11:33:06 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:33:06 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:33:06 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:33:06 volumio ntpd[705]: Soliciting pool server 143.107.229.211 Nov 02 11:33:07 volumio volumio[745]: STREAMING PROXY: Starting server on port 3245 Nov 02 11:33:07 volumio volumio[745]: Node JS runtime: 14 Nov 02 11:33:07 volumio ntpd[705]: Soliciting pool server 200.160.7.197 Nov 02 11:33:07 volumio volumio[745]: info: MyVolumio token set successfully Nov 02 11:33:07 volumio volumio[745]: info: MYVOLUMIO: Adding device Nov 02 11:33:07 volumio volumio[745]: info: MYVOLUMIO: Evaluating Server Nov 02 11:33:08 volumio volumio[745]: info: MyVolumio status changed Nov 02 11:33:08 volumio volumio[745]: info: Streaming services startup Nov 02 11:33:08 volumio volumio[745]: info: Starting Streaming Daemon Nov 02 11:33:08 volumio volumio[745]: info: Removing browser output: myVolumio user plan is not superstar Nov 02 11:33:08 volumio volumio[745]: info: Removing audio output: Nov 02 11:33:08 volumio volumio[745]: info: Stoppping Tunnel 1 Nov 02 11:33:08 volumio sudo[1296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 11:33:08 volumio sudo[1296]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 02 11:33:08 volumio sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio sudo[1296]: pam_unix(sudo:session): session closed for user root Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:08 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 55 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 33 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 28 milliseconds Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:08 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:33:08 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:33:08 volumio volumio[745]: info: Nov 02 11:33:08 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:08 volumio sudo[1299]: pam_unix(sudo:session): session closed for user root Nov 02 11:33:08 volumio volumio[745]: error: Cannot start Volumio Streaming Daemon Nov 02 11:33:08 volumio volumio[745]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 11:33:08 volumio volumio[745]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:33:08 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 74ms Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 71 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 60 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 59 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 58 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 55ms Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 53 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 50ms Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand status took 48 milliseconds Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1085,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1085,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:33:08 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1085,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:33:08 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 214ms Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 236ms Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 214ms Nov 02 11:33:08 volumio volumio[745]: info: Remote SSH Stopped Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 140 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 133 milliseconds Nov 02 11:33:08 volumio volumio[745]: info: sendMpdCommand playlistinfo took 132 milliseconds Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1177,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:33:08 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1177,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:33:08 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1177,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"stream","artist":"arlondon","album":null,"uri":"http://88.208.244.107:8002/stream","trackType":""} Nov 02 11:33:08 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:33:08 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:08 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 336ms Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 316ms Nov 02 11:33:08 volumio volumio[745]: info: ------------------------------ 312ms Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:08 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:09 volumio volumio[745]: info: Setting Geolocation for MyVolumio to us1 Nov 02 11:33:09 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:09 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:09 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:10 volumio volumio[745]: info: Updating MyVolumio device info Nov 02 11:33:10 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:12 volumio ntpd[705]: receive: Unexpected origin timestamp 0xecb1ea27.3bc9deae does not match aorg 0000000000.00000000 from server@200.189.40.8 xmt 0xecb1ea28.d66ef6c6 Nov 02 11:33:13 volumio volumio[745]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 02 11:33:13 volumio volumio[745]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 02 11:33:15 volumio volumio[1017]: ...................................................................................................++++ Nov 02 11:33:17 volumio volumio[745]: info: MYVOLUMIO: Adding device Nov 02 11:33:17 volumio volumio[745]: info: MYVOLUMIO: Evaluating Server Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 02 11:33:18 volumio volumio[745]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::volumioGetState Nov 02 11:33:18 volumio volumio-remote-updater[458]: No test mode Nov 02 11:33:18 volumio volumio-remote-updater[458]: No alpha test mode Nov 02 11:33:18 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 02 11:33:19 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Nov 02 11:33:19 volumio volumio[745]: info: In handleBrowseUri, curUri=spotify Nov 02 11:33:19 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:19 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:19 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:19 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:19 volumio volumio[745]: info: Setting Geolocation for MyVolumio to us1 Nov 02 11:33:19 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:19 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:20 volumio volumio[745]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 02 11:33:20 volumio volumio[745]: info: Updating MyVolumio device info Nov 02 11:33:20 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:21 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Nov 02 11:33:21 volumio volumio[745]: info: In handleBrowseUri, curUri=spotify/myrecentlyplayedtracks Nov 02 11:33:21 volumio volumio[745]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 02 11:33:21 volumio volumio[745]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 02 11:33:21 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 02 11:33:22 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:22 volumio volumio[745]: info: Preloading song: spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:5NP2CygJwj219Tzmvvd7r4 in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:2995D63yimdhCBXoZo0gi3 in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:1B6ZuplkreYHk1kC3YCnPf in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:4NbSRHsYNyoR6k79xmF8Wt in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:1hRhrMiut29W4Pqf9ResLh in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:1BNN6dodoSxgqyOsD5DCAp in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5NP2CygJwj219Tzmvvd7r4","service":"spop","name":"There Is A Higher Throne - Live","artist":"Geraldine Latty","album":"There Is A Higher Throne (Live Worship from Focusfest 2007)","type":"song","duration":339,"albumart":"https://i.scdn.co/image/ab67616d0000b273081636086587030ab8767fe2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:7AGKgEnz1x3nsmb9g2YOXi in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:2XL2WS0F8GiDqQb30SFxn9 in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:5BEfUvwPhKNSMbDGF6BXlU in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4NbSRHsYNyoR6k79xmF8Wt","service":"spop","name":"There Is A Redeemer","artist":"The Mandate","album":"See What A Morning","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b273bf7f1152dc0f72ca39c89a9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1B6ZuplkreYHk1kC3YCnPf","service":"spop","name":"I Just Want to Praise You [Instrumental]","artist":"Integrity Worship Musicians","album":"The Touch: Classical Praise Guitar By Interludes","type":"song","duration":161,"albumart":"https://i.scdn.co/image/ab67616d0000b273ffd800062eccce7449e51700","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:2DqxHth27R5x0cf9SQAjGB in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2995D63yimdhCBXoZo0gi3","service":"spop","name":"Te Louvamos & Oferta de Amor","artist":"Ministério Koinonya de Louvor","album":"Adoração 4 - Eternamente","type":"song","duration":443,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb0363eb5b37d3020370f7f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ","service":"spop","name":"First Loved Me - Original Key Without Background Vocals","artist":"Covenant Worship","album":"First Loved Me","type":"song","duration":437,"albumart":"https://i.scdn.co/image/ab67616d0000b2735878bc2439ae92d041bf94a2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:0WzbX72nsKsk4wBHSKCJCg in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1hRhrMiut29W4Pqf9ResLh","service":"spop","name":"A Vitória Só Vem do Senhor / Magnifico Deus","artist":"Grupo Ágape","album":"Jesus Meu Guia","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b2737df5dee323b8d552419d0470","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:1BNN6dodoSxgqyOsD5DCAp in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7AGKgEnz1x3nsmb9g2YOXi","service":"spop","name":"Meu Prazer - Ao Vivo","artist":"Ministério Ebenézer de Louvor","album":"Quero Alegrar Teu Coração (Gravado em 2002 Ao Vivo)","type":"song","duration":361,"albumart":"https://i.scdn.co/image/ab67616d0000b273c227cfdf758f38b4bb6e6cba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1BNN6dodoSxgqyOsD5DCAp","service":"spop","name":"Glória ao Rei dos Reis","artist":"Grupo Ágape","album":"Sobre as Águas","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b2732e7367d841dc393c31bd7b35","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:4tRK8G0rUBskPplM0Xnchc in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2XL2WS0F8GiDqQb30SFxn9","service":"spop","name":"Nova Estrada","artist":"Novo Som","album":"Pra Sempre, Vol. 2","type":"song","duration":272,"albumart":"https://i.scdn.co/image/ab67616d0000b273d7c1554984e8136d38ff4c01","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:4tRK8G0rUBskPplM0Xnchc in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5BEfUvwPhKNSMbDGF6BXlU","service":"spop","name":"Senhor me alegro em Ti","artist":"Asaph Borba","album":"Jubileu 25 Anos","type":"song","duration":265,"albumart":"https://i.scdn.co/image/ab67616d0000b273fc7e9eb4733a29e4a2e0076e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:4c0L5vof7EAEq45JpP7WSi in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:22 volumio volumio[745]: info: Exploding uri spotify:track:1Js5ngb88NpFUSe3W7jNg9 in service spop Nov 02 11:33:22 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2DqxHth27R5x0cf9SQAjGB","service":"spop","name":"Nada Alem do Sangue: Piano Instrumental","artist":"Wandinho Nonato","album":"Nada Alem do Sangue: Piano Instrumental","type":"song","duration":138,"albumart":"https://i.scdn.co/image/ab67616d0000b273d50b1f77ec5354e1535dc05e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0WzbX72nsKsk4wBHSKCJCg","service":"spop","name":"Tu És Bom (Em Todo o Tempo)","artist":"Eyshila","album":"Tu És Bom (Em Todo o Tempo)","type":"song","duration":350,"albumart":"https://i.scdn.co/image/ab6742d3000053b7f7bf8bf26b6c6f34b4658f87","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:1hRhrMiut29W4Pqf9ResLh in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1BNN6dodoSxgqyOsD5DCAp","service":"spop","name":"Glória ao Rei dos Reis","artist":"Grupo Ágape","album":"Sobre as Águas","type":"song","duration":279,"albumart":"https://i.scdn.co/image/ab67616d0000b2732e7367d841dc393c31bd7b35","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:3D59G7baOncrWHnGJHsKuC in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:23 volumio volumio[745]: info: Using cached record of: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:32XNcky8iTvWl5ZgItZ6UA in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4tRK8G0rUBskPplM0Xnchc","service":"spop","name":"Fonte de Alegria","artist":"Projeto Vida Nova de Irajá","album":"Jesus Fonte de Alegria","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273060599705b7d3ad00b97d819","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4tRK8G0rUBskPplM0Xnchc","service":"spop","name":"Fonte de Alegria","artist":"Projeto Vida Nova de Irajá","album":"Jesus Fonte de Alegria","type":"song","duration":207,"albumart":"https://i.scdn.co/image/ab67616d0000b273060599705b7d3ad00b97d819","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:3o02kNDMk3mRV7DgjgwX7o in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Js5ngb88NpFUSe3W7jNg9","service":"spop","name":"Tributai","artist":"Projeto Vida Nova de Irajá","album":"Jesus Fonte de Alegria","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273060599705b7d3ad00b97d819","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4c0L5vof7EAEq45JpP7WSi","service":"spop","name":"As Nossa Armas São Espirituais","artist":"Projeto Vida Nova de Irajá","album":"Jesus Fonte de Alegria","type":"song","duration":252,"albumart":"https://i.scdn.co/image/ab67616d0000b273060599705b7d3ad00b97d819","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:06d9sZ2X6rxgtjdc5t1psN in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::volumioGetBrowseSources Nov 02 11:33:23 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:08NT71OGBo7pOzS2lgBr47 in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:7f6i1XFRrrJyySnW2NRvtn in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1hRhrMiut29W4Pqf9ResLh","service":"spop","name":"A Vitória Só Vem do Senhor / Magnifico Deus","artist":"Grupo Ágape","album":"Jesus Meu Guia","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b2737df5dee323b8d552419d0470","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:08NT71OGBo7pOzS2lgBr47 in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:16OBYexg5VxVYs1i0rfdWy in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:67JxDqhu3r2Ow8UvCjg7BB in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3D59G7baOncrWHnGJHsKuC","service":"spop","name":"Aleluia / Jesus","artist":"Ministério Life","album":"Ao Nome de Jesus","type":"song","duration":274,"albumart":"https://i.scdn.co/image/ab67616d0000b2734a13fabb51353bfc9c2d317d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:32XNcky8iTvWl5ZgItZ6UA","service":"spop","name":"First Loved Me - Live","artist":"Covenant Worship","album":"Kingdom","type":"song","duration":444,"albumart":"https://i.scdn.co/image/ab67616d0000b2736c3081efc96e132ac01fc698","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:6sy11eiOmNVH5t5qzD3J0X in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:6GpWAiGRcocaswGMEbIZ03 in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3o02kNDMk3mRV7DgjgwX7o","service":"spop","name":"Sê Feliz","artist":"Prisma Brasil","album":"Discípulo Teu","type":"song","duration":278,"albumart":"https://i.scdn.co/image/ab67616d0000b273f824518103c2ed822d2f795a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:08vjXzjH48QsHHrraDMJLn in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:08vjXzjH48QsHHrraDMJLn in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7f6i1XFRrrJyySnW2NRvtn","service":"spop","name":"Resposta ao Teu Amor","artist":"Luciana Debortoli","album":"Resposta ao Teu Amor","type":"song","duration":289,"albumart":"https://i.scdn.co/image/ab67616d0000b2732681f6f7408fc6c34ecd30c3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:06d9sZ2X6rxgtjdc5t1psN","service":"spop","name":"Nasceu o Redentor","artist":"Luciana Debortoli","album":"Música Congregacional","type":"song","duration":374,"albumart":"https://i.scdn.co/image/ab67616d0000b2736f5f0053d187c6f89af4f747","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:3o87VfL7i5rnWy9flYblxM in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08NT71OGBo7pOzS2lgBr47","service":"spop","name":"Quem nos Separará?","artist":"Luciana Debortoli","album":"Quem nos Separará?","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273d704a009e530541f800c9489","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:4rtyV2gthc3k6D0rjcQJOR in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08NT71OGBo7pOzS2lgBr47","service":"spop","name":"Quem nos Separará?","artist":"Luciana Debortoli","album":"Quem nos Separará?","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273d704a009e530541f800c9489","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:16OBYexg5VxVYs1i0rfdWy","service":"spop","name":"Eu Vou Me Derreter","artist":"Comunidade Evangélica Internacional da Zona Sul","album":"Geração de Apaixonados","type":"song","duration":270,"albumart":"https://i.scdn.co/image/ab67616d0000b2739a7f4641f16931ce62c08fa9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:0thdNdCqQPvwtB523r8Xor in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:23 volumio volumio[745]: info: Exploding uri spotify:track:3o87VfL7i5rnWy9flYblxM in service spop Nov 02 11:33:23 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:67JxDqhu3r2Ow8UvCjg7BB","service":"spop","name":"To Be In Your Presence","artist":"Cathy Burton","album":"Love Songs From Heaven: The Worship Songs Of Noel Richards","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b2733b4aebbe940c978c20267988","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:4rtyV2gthc3k6D0rjcQJOR in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6sy11eiOmNVH5t5qzD3J0X","service":"spop","name":"Deus","artist":"Conjunto Sonoros","album":"A Sua Paz Espiritual","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b2731143bb6ec113b852fb812ab0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:2RBJG7fUmrSEIVgnABt3N4 in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:67eVa5gXIHMbAAzSsTzP1x in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:6bLEzrH4NeS6mrbjON5hYI in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:296zuR5Pd1fnajbYnEmNOU in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:2aTs4WZusNNV6aRZLNInPA in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:6C9zHADMy193X63AX9FKs2 in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6GpWAiGRcocaswGMEbIZ03","service":"spop","name":"We Come To You","artist":"Marc Chopinsky","album":"Israel's Hope","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b273966f48c27951d2d7297c59d5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:2puAtREYwiDFxkVEO3bZzZ in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4rtyV2gthc3k6D0rjcQJOR","service":"spop","name":"Obrigado Jesus","artist":"Alda Célia","album":"Jardim Secreto da Adoração","type":"song","duration":259,"albumart":"https://i.scdn.co/image/ab67616d0000b2733d6dc63c0f076b85eb06a3d4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:2tSbtXB2IDMQ6B0let92CE in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:37A4rjZnpYVKPO0QRO12ls in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08vjXzjH48QsHHrraDMJLn","service":"spop","name":"Tu Me Amaste Antes - Ao Vivo","artist":"Bíblica da Paz","album":"Coroado (Ao Vivo)","type":"song","duration":277,"albumart":"https://i.scdn.co/image/ab67616d0000b273d237f1575037036578a29c07","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2RBJG7fUmrSEIVgnABt3N4","service":"spop","name":"Throne Room","artist":"One Way Home","album":"More Than a god - EP","type":"song","duration":267,"albumart":"https://i.scdn.co/image/ab67616d0000b2731e733a75676856573f84867f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:08vjXzjH48QsHHrraDMJLn","service":"spop","name":"Tu Me Amaste Antes - Ao Vivo","artist":"Bíblica da Paz","album":"Coroado (Ao Vivo)","type":"song","duration":277,"albumart":"https://i.scdn.co/image/ab67616d0000b273d237f1575037036578a29c07","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:37A4rjZnpYVKPO0QRO12ls in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:24 volumio volumio[745]: info: Exploding uri spotify:track:1CKm9A8SCnbypSe78yPkKB in service spop Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6bLEzrH4NeS6mrbjON5hYI","service":"spop","name":"Salmo 139","artist":"Veredas","album":"Cotidiano","type":"song","duration":244,"albumart":"https://i.scdn.co/image/ab67616d0000b273989fdd678519d0a03b403937","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3o87VfL7i5rnWy9flYblxM","service":"spop","name":"Poder da Oração","artist":"Alda Célia","album":"Voar Como a Águia","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2737982e4e96c30fdef566d5649","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0thdNdCqQPvwtB523r8Xor","service":"spop","name":"Chuva de Avivamento","artist":"Alda Célia","album":"Jardim Secreto da Adoração","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b2733d6dc63c0f076b85eb06a3d4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3o87VfL7i5rnWy9flYblxM","service":"spop","name":"Poder da Oração","artist":"Alda Célia","album":"Voar Como a Águia","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2737982e4e96c30fdef566d5649","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4rtyV2gthc3k6D0rjcQJOR","service":"spop","name":"Obrigado Jesus","artist":"Alda Célia","album":"Jardim Secreto da Adoração","type":"song","duration":259,"albumart":"https://i.scdn.co/image/ab67616d0000b2733d6dc63c0f076b85eb06a3d4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:67eVa5gXIHMbAAzSsTzP1x","service":"spop","name":"Soberano Rei","artist":"Grupo Áquila","album":"Solos (Especial de Páscoa)","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b273aa07ca55b487d88887ec728f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:296zuR5Pd1fnajbYnEmNOU","service":"spop","name":"Sê Exaltado","artist":"Veredas","album":"Cotidiano","type":"song","duration":199,"albumart":"https://i.scdn.co/image/ab67616d0000b273989fdd678519d0a03b403937","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2aTs4WZusNNV6aRZLNInPA","service":"spop","name":"Reconhecidos","artist":"Vencedores por Cristo","album":"A Visita","type":"song","duration":284,"albumart":"https://i.scdn.co/image/ab67616d0000b273ad9142adfd1555f676c98843","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6C9zHADMy193X63AX9FKs2","service":"spop","name":"No Meio dos Temporais","artist":"Vencedores por Cristo","album":"A Visita","type":"song","duration":281,"albumart":"https://i.scdn.co/image/ab67616d0000b273ad9142adfd1555f676c98843","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2puAtREYwiDFxkVEO3bZzZ","service":"spop","name":"Está Consumado","artist":"Stenio Marcius","album":"Está Consumado","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2736158652a492a5213a529f29d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2tSbtXB2IDMQ6B0let92CE","service":"spop","name":"A Capa e o Mestre","artist":"Stenio Marcius","album":"A Beleza do Rei","type":"song","duration":195,"albumart":"https://i.scdn.co/image/ab67616d0000b27346e47d3fa065bc95914c5a73","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37A4rjZnpYVKPO0QRO12ls","service":"spop","name":"A Beleza do Rei","artist":"Stenio Marcius","album":"A Beleza do Rei","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b27346e47d3fa065bc95914c5a73","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:37A4rjZnpYVKPO0QRO12ls","service":"spop","name":"A Beleza do Rei","artist":"Stenio Marcius","album":"A Beleza do Rei","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b27346e47d3fa065bc95914c5a73","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:24 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1CKm9A8SCnbypSe78yPkKB","service":"spop","name":"O Homem Que Eu Queria Ser","artist":"Stenio Marcius","album":"O Homem Que Eu Queria Ser","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b273f8694e2796bc77a4fbae7a15","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:25 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::stPlaybackTimer Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::serviceStop Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::serviceStop Nov 02 11:33:25 volumio volumio[745]: info: [1762094005048] ControllerWebradio::stop Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:33:25 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::play index 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:33:25 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:25 volumio volumio[745]: info: Exploding uri spotify:track:7AGKgEnz1x3nsmb9g2YOXi in service spop Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:25 volumio volumio[745]: info: Exploding uri spotify:track:7AGKgEnz1x3nsmb9g2YOXi in service spop Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: EXPLODING URI:spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:25 volumio volumio[745]: info: Adding Item to queue: spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:25 volumio volumio[745]: info: Using cached record of: spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: [1762094005151] ControllerSpotify::clearAddPlayTrack Nov 02 11:33:25 volumio volumio[745]: info: Sending Spotify command with payload to local API: /player/play Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:25 volumio volumio[745]: info: Nov 02 11:33:25 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand stop took 137 milliseconds Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:25 volumio volumio[745]: info: Nov 02 11:33:25 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:25 volumio volumio[745]: info: Nov 02 11:33:25 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand status took 18 milliseconds Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand status took 15 milliseconds Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand status took 13 milliseconds Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:33:25 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:33:25 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:33:25 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand playlistinfo took 8 milliseconds Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand playlistinfo took 8 milliseconds Nov 02 11:33:25 volumio volumio[745]: info: sendMpdCommand playlistinfo took 8 milliseconds Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:25 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Nov 02 11:33:25 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:25 volumio volumio[745]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Nov 02 11:33:25 volumio volumio[745]: info: ------------------------------ 109ms Nov 02 11:33:25 volumio volumio[745]: info: ------------------------------ 105ms Nov 02 11:33:25 volumio volumio[745]: info: ------------------------------ 102ms Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7AGKgEnz1x3nsmb9g2YOXi","service":"spop","name":"Meu Prazer - Ao Vivo","artist":"Ministério Ebenézer de Louvor","album":"Quero Alegrar Teu Coração (Gravado em 2002 Ao Vivo)","type":"song","duration":361,"albumart":"https://i.scdn.co/image/ab67616d0000b273c227cfdf758f38b4bb6e6cba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:25 volumio volumio[745]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7AGKgEnz1x3nsmb9g2YOXi","service":"spop","name":"Meu Prazer - Ao Vivo","artist":"Ministério Ebenézer de Louvor","album":"Quero Alegrar Teu Coração (Gravado em 2002 Ao Vivo)","type":"song","duration":361,"albumart":"https://i.scdn.co/image/ab67616d0000b273c227cfdf758f38b4bb6e6cba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Nov 02 11:33:25 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:25 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:33:25 volumio volumio[745]: info: An error occurred saving queue to disk: Error: ENOSPC: no space left on device, write Nov 02 11:33:26 volumio volumio[1017]: ...........................................++++ Nov 02 11:33:26 volumio volumio[1017]: e is 65537 (0x010001) Nov 02 11:33:26 volumio volumio[1017]: writing RSA key Nov 02 11:33:26 volumio volumio[745]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 02 11:33:26 volumio volumio[745]: info: Completed starting MyVolumio Plugin Nov 02 11:33:26 volumio volumio[745]: [Metrics] CommandRouter: 79s 924.34ms Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::volumiosetStartupVolume Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 11:33:26 volumio volumio[745]: info: VolumeController:: Setting startup Volume 30 Nov 02 11:33:26 volumio volumio[745]: info: VolumeController::SetAlsaVolume30 Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::Close All Modals sent Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::Close All Modals sent Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::volumioGetState Nov 02 11:33:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:26 volumio volumio[745]: [ytcr.VolumeControl] Setting volume to 30 Nov 02 11:33:26 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:33:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:33:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:33:26 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:33:26 volumio volumio[745]: SPOTIFY: SPOTIFY VOLUME 95 Nov 02 11:33:26 volumio volumio[745]: SPOTIFY: VOLUMIO VOLUME 30 Nov 02 11:33:26 volumio volumio[745]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 02 11:33:26 volumio volumio[745]: info: Setting Spotify Volume from Volumio: 30 Nov 02 11:33:27 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 02 11:33:27 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 02 11:33:27 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 02 11:33:27 volumio volumio[745]: SPOTIFY: SETTING SPOTIFY VOLUME 30 Nov 02 11:33:27 volumio volumio[745]: info: Sending Spotify command with payload to local API: /player/volume Nov 02 11:33:33 volumio volumio[745]: info: BOOT COMPLETED Nov 02 11:33:52 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:52 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:52 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:33:52 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:5NP2CygJwj219Tzmvvd7r4 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2995D63yimdhCBXoZo0gi3 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1B6ZuplkreYHk1kC3YCnPf Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4NbSRHsYNyoR6k79xmF8Wt Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:0LU44ZGRnHHMt9Ur6DdfQQ Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2XL2WS0F8GiDqQb30SFxn9 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:5BEfUvwPhKNSMbDGF6BXlU Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2DqxHth27R5x0cf9SQAjGB Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:0WzbX72nsKsk4wBHSKCJCg Nov 02 11:33:52 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:33:52 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::play index 11 Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:33:52 volumio volumio[745]: info: Preload queue cleared Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4tRK8G0rUBskPplM0Xnchc Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4c0L5vof7EAEq45JpP7WSi Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1Js5ngb88NpFUSe3W7jNg9 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1BNN6dodoSxgqyOsD5DCAp Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1hRhrMiut29W4Pqf9ResLh Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:3D59G7baOncrWHnGJHsKuC Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:7AGKgEnz1x3nsmb9g2YOXi Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:32XNcky8iTvWl5ZgItZ6UA Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:3o02kNDMk3mRV7DgjgwX7o Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:06d9sZ2X6rxgtjdc5t1psN Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:7f6i1XFRrrJyySnW2NRvtn Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:08NT71OGBo7pOzS2lgBr47 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:16OBYexg5VxVYs1i0rfdWy Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:67JxDqhu3r2Ow8UvCjg7BB Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:6sy11eiOmNVH5t5qzD3J0X Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:6GpWAiGRcocaswGMEbIZ03 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:08vjXzjH48QsHHrraDMJLn Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:0thdNdCqQPvwtB523r8Xor Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:3o87VfL7i5rnWy9flYblxM Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:4rtyV2gthc3k6D0rjcQJOR Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2RBJG7fUmrSEIVgnABt3N4 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:67eVa5gXIHMbAAzSsTzP1x Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:6bLEzrH4NeS6mrbjON5hYI Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:296zuR5Pd1fnajbYnEmNOU Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2aTs4WZusNNV6aRZLNInPA Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:6C9zHADMy193X63AX9FKs2 Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2puAtREYwiDFxkVEO3bZzZ Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:2tSbtXB2IDMQ6B0let92CE Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:37A4rjZnpYVKPO0QRO12ls Nov 02 11:33:52 volumio volumio[745]: info: Adding Item to queue: spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:52 volumio volumio[745]: info: Using cached record of: spotify:track:1CKm9A8SCnbypSe78yPkKB Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:52 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::getTrack 11 Nov 02 11:33:52 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:33:52 volumio volumio[745]: info: CorePlayQueue::getTrack 11 Nov 02 11:33:52 volumio volumio[745]: info: [1762094032431] ControllerSpotify::clearAddPlayTrack Nov 02 11:33:52 volumio volumio[745]: info: Sending Spotify command with payload to local API: /player/play Nov 02 11:33:52 volumio volumio[745]: info: An error occurred saving queue to disk: Error: ENOSPC: no space left on device, write Nov 02 11:33:52 volumio volumio[745]: info: An error occurred saving queue to disk: Error: ENOSPC: no space left on device, write Nov 02 11:33:52 volumio volumio[745]: info: An error occurred saving queue to disk: Error: ENOSPC: no space left on device, write Nov 02 11:33:58 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: soundcloud , handleBrowseUri Nov 02 11:33:58 volumio volumio[745]: info: [soundcloud] browseUri: soundcloud Nov 02 11:34:01 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:01 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:06 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Nov 02 11:34:06 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:07 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Nov 02 11:34:07 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:10 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:10 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:10 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:34:10 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:10 volumio volumio[745]: info: Adding Item to queue: http://ice64.securenetsystems.net/CLR1MP3 Nov 02 11:34:10 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Nov 02 11:34:10 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:34:10 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::play index 0 Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:10 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:34:10 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:10 volumio volumio[745]: info: [1762094050128] ControllerWebradio::clearAddPlayTrack Nov 02 11:34:10 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:34:10 volumio volumio[745]: info: sendMpdCommand stop took 17 milliseconds Nov 02 11:34:10 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 11:34:10 volumio volumio[745]: info: Nov 02 11:34:10 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:10 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:10 volumio volumio[745]: info: sendMpdCommand clear took 7 milliseconds Nov 02 11:34:10 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand load "http://ice64.securenetsystems.net/CLR1MP3" Nov 02 11:34:10 volumio volumio[745]: info: Nov 02 11:34:10 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:10 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:10 volumio volumio[745]: info: Nov 02 11:34:10 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:10 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:10 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:10 volumio volumio[745]: info: ------------------------------ 30ms Nov 02 11:34:10 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:10 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:10 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand add "http://ice64.securenetsystems.net/CLR1MP3" Nov 02 11:34:11 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:11 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 1012ms Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 1009ms Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand add "http://ice64.securenetsystems.net/CLR1MP3" took 8 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand play Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 32ms Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand play took 21 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 18ms Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 14ms Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 21 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 29 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 26 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 13 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 10 milliseconds Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CLR1MP3","artist":null,"album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 80ms Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 50 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 38 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 37 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 12 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand status took 8 milliseconds Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CLR1MP3","artist":null,"album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:11 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CLR1MP3","artist":null,"album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:11 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CLR1MP3","artist":null,"album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:11 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 312ms Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 309ms Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 300ms Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:11 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 207 milliseconds Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: sendMpdCommand playlistinfo took 209 milliseconds Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:11 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:11 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:11 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:11 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:11 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:11 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 348ms Nov 02 11:34:11 volumio volumio[745]: info: ------------------------------ 345ms Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:11 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:11 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:11 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:11 volumio volumio[745]: info: Nov 02 11:34:11 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 193ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 188 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 193ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 187 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 90ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 69 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 68ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 64 milliseconds Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: info: Nov 02 11:34:12 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:12 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:12 volumio volumio[745]: info: Nov 02 11:34:12 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:12 volumio volumio[745]: info: Nov 02 11:34:12 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:12 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:12 volumio volumio[745]: info: Nov 02 11:34:12 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 34 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 34 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 33 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 33 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 32ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 29 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 29ms Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand status took 19 milliseconds Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1087,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1087,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 439ms Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 438ms Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 336ms Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 318ms Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:12 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 252 milliseconds Nov 02 11:34:12 volumio volumio[745]: info: sendMpdCommand playlistinfo took 251 milliseconds Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1178,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:12 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:12 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1178,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Bebo Norman - Holy, Holy, Holy Lord - ","artist":"Christian Life Radio","album":null,"uri":"http://ice64.securenetsystems.net/CLR1MP3","trackType":""} Nov 02 11:34:12 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:12 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:12 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 371ms Nov 02 11:34:12 volumio volumio[745]: info: ------------------------------ 362ms Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:12 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Nov 02 11:34:16 volumio volumio[745]: info: VolumeController::SetAlsaVolume90 Nov 02 11:34:16 volumio volumio[745]: info: CoreCommandRouter::volumioGetState Nov 02 11:34:16 volumio volumio[745]: [ytcr.VolumeControl] Setting volume to 90 Nov 02 11:34:16 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:16 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:16 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:16 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:16 volumio volumio[745]: SPOTIFY: SPOTIFY VOLUME 30 Nov 02 11:34:16 volumio volumio[745]: SPOTIFY: VOLUMIO VOLUME 90 Nov 02 11:34:16 volumio volumio[745]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 02 11:34:16 volumio volumio[745]: info: Setting Spotify Volume from Volumio: 90 Nov 02 11:34:17 volumio volumio[745]: SPOTIFY: SETTING SPOTIFY VOLUME 90 Nov 02 11:34:17 volumio volumio[745]: info: Sending Spotify command with payload to local API: /player/volume Nov 02 11:34:26 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::stPlaybackTimer Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::serviceStop Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::serviceStop Nov 02 11:34:26 volumio volumio[745]: info: [1762094066164] ControllerWebradio::stop Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:34:26 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:26 volumio volumio[745]: info: Adding Item to queue: http://primary.moodyradiostream.org/wmbifm.mp3 Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::play index 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: [1762094066208] ControllerWebradio::clearAddPlayTrack Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:34:26 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand stop took 57 milliseconds Nov 02 11:34:26 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand stop took 15 milliseconds Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:26 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:26 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:26 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand status took 16 milliseconds Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand clear took 15 milliseconds Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand status took 19 milliseconds Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand status took 15 milliseconds Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand load "http://primary.moodyradiostream.org/wmbifm.mp3" Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:26 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Nov 02 11:34:26 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:26 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:26 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:26 volumio volumio[745]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Nov 02 11:34:26 volumio volumio[745]: info: ------------------------------ 79ms Nov 02 11:34:26 volumio volumio[745]: info: ------------------------------ 77ms Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:26 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:26 volumio volumio[745]: info: Nov 02 11:34:26 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:26 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:26 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:26 volumio volumio[745]: info: ------------------------------ 81ms Nov 02 11:34:26 volumio volumio[745]: info: sendMpdCommand playlistinfo took 68 milliseconds Nov 02 11:34:26 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:26 volumio volumio[745]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 02 11:34:26 volumio volumio[745]: info: ------------------------------ 101ms Nov 02 11:34:26 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:26 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:26 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:27 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand add "http://primary.moodyradiostream.org/wmbifm.mp3" Nov 02 11:34:27 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:27 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:27 volumio volumio[745]: info: Nov 02 11:34:27 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:27 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:27 volumio volumio[745]: info: ------------------------------ 1482ms Nov 02 11:34:27 volumio volumio[745]: info: ------------------------------ 1481ms Nov 02 11:34:27 volumio volumio[745]: info: sendMpdCommand add "http://primary.moodyradiostream.org/wmbifm.mp3" took 6 milliseconds Nov 02 11:34:27 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 02 11:34:27 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand play Nov 02 11:34:27 volumio volumio[745]: info: Nov 02 11:34:27 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:27 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:27 volumio volumio[745]: info: Nov 02 11:34:27 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:27 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:27 volumio volumio[745]: info: ------------------------------ 20ms Nov 02 11:34:27 volumio volumio[745]: info: sendMpdCommand play took 17 milliseconds Nov 02 11:34:27 volumio volumio[745]: info: ------------------------------ 13ms Nov 02 11:34:27 volumio volumio[745]: info: ------------------------------ 9ms Nov 02 11:34:27 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:27 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:27 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:28 volumio volumio[745]: info: Nov 02 11:34:28 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:28 volumio volumio[745]: info: Nov 02 11:34:28 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:28 volumio volumio[745]: info: Nov 02 11:34:28 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand status took 32 milliseconds Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand status took 31 milliseconds Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand status took 30 milliseconds Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:28 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:28 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:28 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand clearerror took 30 milliseconds Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand clearerror took 26 milliseconds Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand clearerror took 25 milliseconds Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand playlistinfo took 8 milliseconds Nov 02 11:34:28 volumio volumio[745]: info: sendMpdCommand playlistinfo took 8 milliseconds Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:28 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:28 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"wmbifm.mp3","artist":null,"album":null,"uri":"http://primary.moodyradiostream.org/wmbifm.mp3","trackType":"mp3"} Nov 02 11:34:28 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: No code Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:28 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"wmbifm.mp3","artist":null,"album":null,"uri":"http://primary.moodyradiostream.org/wmbifm.mp3","trackType":"mp3"} Nov 02 11:34:28 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: No code Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:28 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"wmbifm.mp3","artist":null,"album":null,"uri":"http://primary.moodyradiostream.org/wmbifm.mp3","trackType":"mp3"} Nov 02 11:34:28 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:28 volumio volumio[745]: info: No code Nov 02 11:34:28 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:28 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 265ms Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 264ms Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 263ms Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:29 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:29 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:29 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:34:29 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:29 volumio volumio[745]: info: Adding Item to queue: https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8 Nov 02 11:34:29 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Nov 02 11:34:29 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:34:29 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::play index 0 Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:34:29 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:29 volumio volumio[745]: info: [1762094069799] ControllerWebradio::clearAddPlayTrack Nov 02 11:34:29 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:34:29 volumio volumio[745]: info: sendMpdCommand stop took 9 milliseconds Nov 02 11:34:29 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: info: sendMpdCommand clear took 2 milliseconds Nov 02 11:34:29 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand add "https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8" Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 13ms Nov 02 11:34:29 volumio volumio[745]: info: sendMpdCommand add "https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8" took 11 milliseconds Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 11ms Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 9ms Nov 02 11:34:29 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 02 11:34:29 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand play Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: info: Nov 02 11:34:29 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:29 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 14ms Nov 02 11:34:29 volumio volumio[745]: info: sendMpdCommand play took 10 milliseconds Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 8ms Nov 02 11:34:29 volumio volumio[745]: info: ------------------------------ 7ms Nov 02 11:34:29 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:29 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:29 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:30 volumio volumio[745]: info: Nov 02 11:34:30 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:30 volumio volumio[745]: info: Nov 02 11:34:30 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:30 volumio volumio[745]: info: Nov 02 11:34:30 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand status took 20 milliseconds Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand status took 20 milliseconds Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clearerror Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand status took 20 milliseconds Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:30 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:30 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:30 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand clearerror took 41 milliseconds Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand clearerror took 38 milliseconds Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand clearerror took 36 milliseconds Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 02 11:34:30 volumio volumio[745]: info: sendMpdCommand playlistinfo took 7 milliseconds Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:30 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:30 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8","trackType":"m3u8"} Nov 02 11:34:30 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: No code Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:30 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8","trackType":"m3u8"} Nov 02 11:34:30 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: No code Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:30 volumio volumio[745]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"playlist.m3u8","artist":null,"album":null,"uri":"https://evpp.mm.uol.com.br/band/radiobandeirantes_poa/playlist.m3u8","trackType":"m3u8"} Nov 02 11:34:30 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState stateService stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:30 volumio volumio[745]: info: No code Nov 02 11:34:30 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:30 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:31 volumio volumio[745]: info: ------------------------------ 231ms Nov 02 11:34:31 volumio volumio[745]: info: ------------------------------ 230ms Nov 02 11:34:31 volumio volumio[745]: info: ------------------------------ 229ms Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:31 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:34 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:34 volumio volumio[745]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::ClearQueue Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::clearPlayQueue Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:34 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::addQueueItems Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::addQueueItems Nov 02 11:34:34 volumio volumio[745]: info: Preload queue cleared Nov 02 11:34:34 volumio volumio[745]: info: Adding Item to queue: http://radio.wanderingsheep.tv:8012/hopealive Nov 02 11:34:34 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Nov 02 11:34:34 volumio volumio[745]: info: CoreCommandRouter::volumioPushQueue Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::saveQueue Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::updateTrackBlock Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::getTrackBlock Nov 02 11:34:34 volumio volumio[745]: info: CoreCommandRouter::volumioPlay Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::play index 0 Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::stop Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::play index undefined Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:34 volumio volumio[745]: info: CoreStateMachine::startPlaybackTimer Nov 02 11:34:34 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:34 volumio volumio[745]: info: [1762094074870] ControllerWebradio::clearAddPlayTrack Nov 02 11:34:34 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand stop Nov 02 11:34:34 volumio volumio[745]: info: sendMpdCommand stop took 7 milliseconds Nov 02 11:34:34 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand clear Nov 02 11:34:34 volumio volumio[745]: info: sendMpdCommand clear took 2 milliseconds Nov 02 11:34:34 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand load "http://radio.wanderingsheep.tv:8012/hopealive" Nov 02 11:34:34 volumio volumio[745]: info: Nov 02 11:34:34 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:34 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:34 volumio volumio[745]: info: Nov 02 11:34:34 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:34 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:34 volumio volumio[745]: info: Nov 02 11:34:34 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:34 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:34 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:34 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:34 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:36 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand add "http://radio.wanderingsheep.tv:8012/hopealive" Nov 02 11:34:36 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:36 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:36 volumio volumio[745]: error: updateQueue error: null Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 1586ms Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 1583ms Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 1582ms Nov 02 11:34:36 volumio volumio[745]: info: Nov 02 11:34:36 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:36 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:36 volumio volumio[745]: info: sendMpdCommand add "http://radio.wanderingsheep.tv:8012/hopealive" took 9 milliseconds Nov 02 11:34:36 volumio volumio[745]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 02 11:34:36 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand play Nov 02 11:34:36 volumio volumio[745]: info: Nov 02 11:34:36 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:36 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:36 volumio volumio[745]: info: Nov 02 11:34:36 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:36 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 16ms Nov 02 11:34:36 volumio volumio[745]: info: sendMpdCommand play took 12 milliseconds Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 12ms Nov 02 11:34:36 volumio volumio[745]: info: ------------------------------ 8ms Nov 02 11:34:36 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:36 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:36 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 18 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 20 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 18 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 6 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 6 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus stop Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 39ms Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 22 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 15 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 11 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 173ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 172ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 162ms Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 126 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 126 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"hopealive","artist":null,"album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 227ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 226ms Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 9ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 6 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 23ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 19 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 18 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 16ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 14 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 13ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 10 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":783,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 86ms Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces system playlist update Nov 02 11:34:37 volumio volumio[745]: info: Ignoring MPD Status Update Nov 02 11:34:37 volumio volumio[745]: info: Nov 02 11:34:37 volumio volumio[745]: ---------------------------- MPD announces state update: player Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::getState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand status Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 68 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 67 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 67 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 15ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 13 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 13ms Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand status took 10 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseState Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":886,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":886,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":886,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 225ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 219ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 215ms Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'playlist' Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem playlist: 0 Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Event received for subsystem 'player' Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventListener] Calling handler.handle()... Nov 02 11:34:37 volumio volumio[745]: [MPDPlayer.MPDEventHandler] Number of callbacks for subsystem player: 1 Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 163 milliseconds Nov 02 11:34:37 volumio volumio[745]: info: sendMpdCommand playlistinfo took 163 milliseconds Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: verbose: ControllerMpd::parseTrackInfo Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":886,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ControllerMpd::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::servicePushState Nov 02 11:34:37 volumio volumio[745]: info: CorePlayQueue::getTrack 0 Nov 02 11:34:37 volumio volumio[745]: verbose: STATE SERVICE {"status":"play","position":0,"seek":886,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cody Carnes & Kari Jobe - Cover The Earth","artist":"Hope Alive","album":null,"uri":"http://radio.wanderingsheep.tv:8012/hopealive","trackType":""} Nov 02 11:34:37 volumio volumio[745]: verbose: CURRENT POSITION 0 Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState stateService play Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::syncState currentStatus play Nov 02 11:34:37 volumio volumio[745]: info: Received an update from plugin. extracting info from payload Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: CoreStateMachine::pushState Nov 02 11:34:37 volumio volumio[745]: info: CoreCommandRouter::volumioPushState Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 271ms Nov 02 11:34:37 volumio volumio[745]: info: ------------------------------ 269ms Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:37 volumio volumio[745]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Nov 02 11:34:40 volumio volumio[745]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 11:34:40 volumio volumio[745]: [Error: ENOSPC: no space left on device, write] { Nov 02 11:34:40 volumio volumio[745]: errno: -28, Nov 02 11:34:40 volumio volumio[745]: code: 'ENOSPC', Nov 02 11:34:40 volumio volumio[745]: syscall: 'write' Nov 02 11:34:40 volumio volumio[745]: } Nov 02 11:34:40 volumio volumio[745]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 11:34:41 volumio sudo[1625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-02 11:33 Nov 02 11:34:41 volumio sudo[1625]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"