-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Thu 2025-05-15 18:16:40 BST. -- May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons initialized May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "outputs"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "albumart"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Plugin example_plugin is not enabled May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "inputs"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "updater_comm"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Plugin mpdemulation is not enabled May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "rest_api"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "websocket"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Starting Socket.io Server version 2.3.0 May 15 18:15:00 main-pi-v3.812 volumio[1037]: info: Loading plugin "backup_restore"... May 15 18:15:00 main-pi-v3.812 volumio[1037]: Forking 3 albumart workers May 15 18:15:01 main-pi-v3.812 volumio[1037]: info: Applying required configuration parameters for plugin backup_restore May 15 18:15:01 main-pi-v3.812 volumio[1037]: info: Loading plugin "gpio_control"... May 15 18:15:01 main-pi-v3.812 volumio[1037]: gpiox_arm32 V2.1.0 May 15 18:15:01 main-pi-v3.812 volumio[1037]: Starting albumart workers May 15 18:15:01 main-pi-v3.812 volumio[1037]: Starting albumart workers May 15 18:15:01 main-pi-v3.812 volumio[1037]: Starting albumart workers May 15 18:15:01 main-pi-v3.812 volumio[1037]: info: Applying required configuration parameters for plugin gpio_control May 15 18:15:01 main-pi-v3.812 volumio[1037]: info: Loading plugin "Systeminfo"... May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: Loading i18n strings for locale en May 15 18:15:02 main-pi-v3.812 volumio[1037]: Updating browse sources language May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::initPlayerControls May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 15 18:15:02 main-pi-v3.812 volumio[1037]: Express server listening on port 3000 May 15 18:15:02 main-pi-v3.812 volumio[1037]: [Metrics] WebUI: 9s 755.01ms May 15 18:15:02 main-pi-v3.812 volumio-remote-updater[613]: [2025-05-15 18:15:02] [connect] Successful connection May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::resetVolumioState May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::getcurrentVolume May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioRetrievevolume May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::getcurrentVolume May 15 18:15:02 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioRetrievevolume May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Volumio Network Manager: Network status updated: 3 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.10 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.10 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 May 15 18:15:03 main-pi-v3.812 volumio-remote-updater[613]: [2025-05-15 18:15:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747329302 101 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Reloading queue from file May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: VolumeController:: Volume=86 Mute =false May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::updateTrackBlock May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrackBlock May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioRetrievevolume May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: VolumeController:: Volume=86 Mute =false May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::updateTrackBlock May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrackBlock May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioRetrievevolume May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setRepeat null single undefined May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setRandom null May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Setting Device type: Raspberry PI May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Completed loading Core Plugins May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Preparing to generate the ALSA configuration file May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: VolumeController:: Volume=86 Mute =false May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Discovery: adding 51b7b070-dadd-4e7b-a19a-00339d52735b May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Discovery: Found device Main Pi (V3.812) May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: VolumeController:: Volume=86 Mute =false May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Discovery: this is already registered, 51b7b070-dadd-4e7b-a19a-00339d52735b May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Discovery: Found device Main Pi (V3.812) May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:03 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.10 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Asound.conf file written May 15 18:15:03 main-pi-v3.812 sudo[1201]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:03 main-pi-v3.812 sudo[1201]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:03 main-pi-v3.812 sudo[1201]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 15 18:15:03 main-pi-v3.812 sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:03 main-pi-v3.812 sudo[1201]: pam_unix(sudo:session): session closed for user root May 15 18:15:03 main-pi-v3.812 volumio[1037]: sudo: unable to resolve host main-pi-v3.812: System error May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: Output device has changed, restarting MPD May 15 18:15:03 main-pi-v3.812 volumio[1037]: info: ___________ START PLUGINS ___________ May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: ControllerMpd::onStart: Initializing MPD May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: Creating MPD Configuration file May 15 18:15:04 main-pi-v3.812 sudo[1206]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:04 main-pi-v3.812 sudo[1206]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:04 main-pi-v3.812 sudo[1206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 15 18:15:04 main-pi-v3.812 sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:04 main-pi-v3.812 sudo[1208]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:04 main-pi-v3.812 sudo[1208]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:04 main-pi-v3.812 sudo[1206]: pam_unix(sudo:session): session closed for user root May 15 18:15:04 main-pi-v3.812 sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 15 18:15:04 main-pi-v3.812 sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [1747329304079] CoreMusicLibrary::Adding element Media Servers May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 18:15:04 main-pi-v3.812 systemd[1]: Stopping Music Player Daemon... May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [1747329304107] CoreMusicLibrary::Adding element Last_100 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [1747329304113] CoreMusicLibrary::Adding element Webradio May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: Initializing BBC Radios May 15 18:15:04 main-pi-v3.812 sudo[1223]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:04 main-pi-v3.812 sudo[1223]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:04 main-pi-v3.812 sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 15 18:15:04 main-pi-v3.812 sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:04 main-pi-v3.812 sudo[1226]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:04 main-pi-v3.812 sudo[1226]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:04 main-pi-v3.812 sudo[1223]: pam_unix(sudo:session): session closed for user root May 15 18:15:04 main-pi-v3.812 sudo[1226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 15 18:15:04 main-pi-v3.812 sudo[1226]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Reading config and creating triggers... May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: playPause on pin 563 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: previous on pin 553 May 15 18:15:04 main-pi-v3.812 systemd[1]: mpd.service: Succeeded. May 15 18:15:04 main-pi-v3.812 systemd[1]: Stopped Music Player Daemon. May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: next on pin 558 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: shutdown on pin 546 May 15 18:15:04 main-pi-v3.812 systemd[1]: Starting Music Player Daemon... May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Reading config and creating GPIOs May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: Volumio Calling Home May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: sdio ctrlframe tx failed err=-110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: failed backplane access over SDIO, halting operation May 15 18:15:04 main-pi-v3.812 kernel: ieee80211 phy0: _brcmf_set_multicast_list: Setting mcast_list failed, -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: sdio ctrlframe tx failed err=-110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: failed backplane access over SDIO, halting operation May 15 18:15:04 main-pi-v3.812 kernel: ieee80211 phy0: _brcmf_set_multicast_list: Setting allmulti failed, -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: sdio ctrlframe tx failed err=-110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: failed backplane access over SDIO, halting operation May 15 18:15:04 main-pi-v3.812 kernel: ieee80211 phy0: _brcmf_set_multicast_list: Setting BRCMF_C_SET_PROMISC failed, err=-110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: sdio ctrlframe tx failed err=-110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: failed backplane access over SDIO, halting operation May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons started May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] GPIOs created May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: systemStartup May 15 18:15:04 main-pi-v3.812 sudo[1253]: root : unable to resolve host main-pi-v3.812 May 15 18:15:04 main-pi-v3.812 sudo[1253]: root : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:04 main-pi-v3.812 sudo[1253]: sudo: unable to resolve host main-pi-v3.812: System error May 15 18:15:04 main-pi-v3.812 sudo[1253]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 15 18:15:04 main-pi-v3.812 sudo[1253]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:04 main-pi-v3.812 sudo[1253]: pam_unix(sudo:session): session closed for user root May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: na May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: na May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: musicStop May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: repeatAllOff May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: repeatOff May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: MPD Permissions set May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: MPD Permissions set May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: na May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: Volumio called home May 15 18:15:04 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:04 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:04 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to 192.168.1.16 from 192.168.1.10 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: Received Get System Info May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 18:15:04 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: Discovery: Getting this device information May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetVisibleSources May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: Received Get System Info May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: Discovery: Getting this device information May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: Listing playlists May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetQueue May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::getQueue May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getQueue May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:05 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: OFF May 15 18:15:05 main-pi-v3.812 kernel: I/O error, dev mmcblk0, sector 2919 op 0x1:(WRITE) flags 0x100000 phys_seg 1 prio class 2 May 15 18:15:05 main-pi-v3.812 kernel: Buffer I/O error on dev mmcblk0p1, logical block 2918, lost async page write May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:06 main-pi-v3.812 mpd[1275]: May 15 18:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 15 18:15:06 main-pi-v3.812 systemd[1]: Started Music Player Daemon. May 15 18:15:06 main-pi-v3.812 sudo[1226]: pam_unix(sudo:session): session closed for user root May 15 18:15:06 main-pi-v3.812 sudo[1208]: pam_unix(sudo:session): session closed for user root May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: Completed starting Core Plugins May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: ------------------------------------------- May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: ----- MyVolumio plugins startup ---- May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: ------------------------------------------- May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Fetching plans data.... May 15 18:15:06 main-pi-v3.812 volumio[1037]: error: MPD error: The expression evaluated to a falsy value: May 15 18:15:06 main-pi-v3.812 volumio[1037]: assert.ok(self.idling) May 15 18:15:06 main-pi-v3.812 volumio[1037]: error: The expression evaluated to a falsy value: May 15 18:15:06 main-pi-v3.812 volumio[1037]: assert.ok(self.idling) May 15 18:15:06 main-pi-v3.812 volumio[1037]: info: MPD running with PID1275 May 15 18:15:06 main-pi-v3.812 volumio[1037]: ,establishing connection May 15 18:15:06 main-pi-v3.812 volumio[1037]: error: MPD error: The expression evaluated to a falsy value: May 15 18:15:06 main-pi-v3.812 volumio[1037]: assert.ok(self.idling) May 15 18:15:06 main-pi-v3.812 volumio[1037]: error: The expression evaluated to a falsy value: May 15 18:15:06 main-pi-v3.812 volumio[1037]: assert.ok(self.idling) May 15 18:15:06 main-pi-v3.812 volumio[1037]: error: updateQueue error: null May 15 18:15:06 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:06 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:07 main-pi-v3.812 systemd[1]: systemd-fsckd.service: Succeeded. May 15 18:15:08 main-pi-v3.812 sudo[1307]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:08 main-pi-v3.812 sudo[1307]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:08 main-pi-v3.812 sudo[1307]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 15 18:15:08 main-pi-v3.812 sudo[1307]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:08 main-pi-v3.812 sudo[1309]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:08 main-pi-v3.812 sudo[1309]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:08 main-pi-v3.812 sudo[1307]: pam_unix(sudo:session): session closed for user root May 15 18:15:08 main-pi-v3.812 sudo[1309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 15 18:15:08 main-pi-v3.812 sudo[1309]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:08 main-pi-v3.812 sudo[1309]: pam_unix(sudo:session): session closed for user root May 15 18:15:08 main-pi-v3.812 sudo[1311]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:08 main-pi-v3.812 sudo[1311]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:08 main-pi-v3.812 sudo[1311]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 15 18:15:08 main-pi-v3.812 sudo[1311]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:08 main-pi-v3.812 systemd[1]: Started UPnP Renderer front-end to MPD. May 15 18:15:08 main-pi-v3.812 sudo[1311]: pam_unix(sudo:session): session closed for user root May 15 18:15:08 main-pi-v3.812 volumio[1037]: info: Upmpdcli Daemon Started May 15 18:15:08 main-pi-v3.812 volumio[1315]: Generating RSA private key, 4096 bit long modulus (2 primes) May 15 18:15:10 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:11 main-pi-v3.812 volumio[1037]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 15 18:15:11 main-pi-v3.812 systemd[1]: systemd-hostnamed.service: Succeeded. May 15 18:15:14 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:14 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin bluetooth to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin multiroom to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin metavolumio to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin cd_controller to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin qobuzconnect to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin smart_inputs to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: Adding plugin tidalconnect to MyMusic Plugins May 15 18:15:14 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 15 18:15:16 main-pi-v3.812 volumio[1315]: .......................................................++++ May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: Starting MyVolumio Remote Streaming Endpoints May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: MyVolumio login type: Token May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 15 18:15:16 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: Starting Streaming Service Transparent Proxy May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: Streaming services startup May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: Starting Streaming Daemon May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 15 18:15:17 main-pi-v3.812 sudo[1355]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:17 main-pi-v3.812 sudo[1355]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:17 main-pi-v3.812 sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 15 18:15:17 main-pi-v3.812 sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:17 main-pi-v3.812 sudo[1355]: pam_unix(sudo:session): session closed for user root May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:17 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 15 18:15:18 main-pi-v3.812 volumio[1037]: error: Cannot start Volumio Streaming Daemon May 15 18:15:18 main-pi-v3.812 volumio[1037]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 15 18:15:18 main-pi-v3.812 volumio[1037]: sudo: unable to resolve host main-pi-v3.812: System error May 15 18:15:18 main-pi-v3.812 volumio[1037]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 15 18:15:18 main-pi-v3.812 volumio[1037]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 15 18:15:18 main-pi-v3.812 volumio[1315]: ....................++++ May 15 18:15:18 main-pi-v3.812 volumio[1315]: e is 65537 (0x010001) May 15 18:15:19 main-pi-v3.812 volumio[1315]: writing RSA key May 15 18:15:19 main-pi-v3.812 volumio[1037]: STREAMING PROXY: Starting server on port 3245 May 15 18:15:19 main-pi-v3.812 volumio[1037]: Node JS runtime: 14 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Preload queue cleared May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioAddQueueItems May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::addQueueItems May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::addQueueItems May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Preload queue cleared May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Adding Item to queue: music-library/NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Exploding uri music-library/NAS/Folder 1; complete tracks/06 Brothers Johnson.flac in service mpd May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ALBUMART /albumart?cacheid=399&path=%2Fmnt%2FNAS%2FFolder%201%3B%20complete%20tracks%2F06%20Brothers%20Johnson.flac&metadata=false May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: URI /mnt/NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushQueue May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::saveQueue May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::updateTrackBlock May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrackBlock May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPlay May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::play index 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stop May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::play index undefined May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::startPlaybackTimer May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::clearAddPlayTracks NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand stop May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand stop took 4 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand clear May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand clear took 23 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand add "NAS/Folder 1; complete tracks/06 Brothers Johnson.flac" May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: error: updateQueue error: null May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 52ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand add "NAS/Folder 1; complete tracks/06 Brothers Johnson.flac" took 48 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 24ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 22ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: MyVolumio token set successfully May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: MYVOLUMIO: Adding device May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: MYVOLUMIO: Evaluating Server May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 22ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand play took 18 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 24 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 24ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 23ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: May 15 18:15:19 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 23 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 17 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 16 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 15 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"599 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus stop May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 64ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 18 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 16 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 16 milliseconds May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"592 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"592 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"592 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:19 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 124ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 115ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: ------------------------------ 113ms May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: stop May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: ON May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: musicPlay May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: MyVolumio status changed May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Streaming services startup May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Starting Streaming Daemon May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Removing browser output: myVolumio user plan is not superstar May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Removing audio output: May 15 18:15:19 main-pi-v3.812 volumio[1037]: info: Stoppping Tunnel 1 May 15 18:15:20 main-pi-v3.812 sudo[1402]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:20 main-pi-v3.812 sudo[1402]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:20 main-pi-v3.812 sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 15 18:15:20 main-pi-v3.812 sudo[1402]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:20 main-pi-v3.812 sudo[1404]: volumio : unable to resolve host main-pi-v3.812 May 15 18:15:20 main-pi-v3.812 sudo[1404]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:15:20 main-pi-v3.812 sudo[1402]: pam_unix(sudo:session): session closed for user root May 15 18:15:20 main-pi-v3.812 sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 15 18:15:20 main-pi-v3.812 sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) May 15 18:15:20 main-pi-v3.812 volumio[1037]: error: Cannot start Volumio Streaming Daemon May 15 18:15:20 main-pi-v3.812 volumio[1037]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 15 18:15:20 main-pi-v3.812 volumio[1037]: sudo: unable to resolve host main-pi-v3.812: System error May 15 18:15:20 main-pi-v3.812 volumio[1037]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 15 18:15:20 main-pi-v3.812 sudo[1404]: pam_unix(sudo:session): session closed for user root May 15 18:15:20 main-pi-v3.812 volumio[1037]: info: Remote SSH Stopped May 15 18:15:20 main-pi-v3.812 volumio[1037]: info: Setting Geolocation for MyVolumio to eu3 May 15 18:15:20 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:20 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:20 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:20 main-pi-v3.812 volumio[1037]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 15 18:15:21 main-pi-v3.812 systemd[1]: systemd-timedated.service: Succeeded. May 15 18:15:21 main-pi-v3.812 volumio[1037]: info: Updating MyVolumio device info May 15 18:15:21 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:21 main-pi-v3.812 volumio[1037]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 15 18:15:24 main-pi-v3.812 volumio[1037]: info: MYVOLUMIO: Adding device May 15 18:15:24 main-pi-v3.812 volumio[1037]: info: MYVOLUMIO: Evaluating Server May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stPlaybackTimer May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::servicePause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: May 15 18:15:25 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand pause took 2 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: May 15 18:15:25 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: May 15 18:15:25 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 6 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 4 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 3 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: Setting Geolocation for MyVolumio to eu3 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 16 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 17 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 16 milliseconds May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6841,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"630 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stPlaybackTimer May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6841,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"630 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stPlaybackTimer May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":6841,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"630 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:25 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stPlaybackTimer May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ------------------------------ 68ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ------------------------------ 66ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: ------------------------------ 65ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: pause PrevState: play May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: pause PrevState: play May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: pause PrevState: play May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: musicPause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: pause May 15 18:15:25 main-pi-v3.812 volumio[1037]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 15 18:15:26 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: OFF May 15 18:15:26 main-pi-v3.812 volumio[1037]: info: Updating MyVolumio device info May 15 18:15:26 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:26 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:26 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:26 main-pi-v3.812 volumio[1037]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPlay May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::play index undefined May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::startPlaybackTimer May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::resume May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand play took 5 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: May 15 18:15:27 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: May 15 18:15:27 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: May 15 18:15:27 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 6 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 4 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 2 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 3 milliseconds May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7824,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"639 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus pause May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7824,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"639 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7824,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"639 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:27 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ------------------------------ 71ms May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ------------------------------ 70ms May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: ------------------------------ 68ms May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: pause May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: ON May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: musicPlay May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:27 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: play May 15 18:15:30 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:30 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:31 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 15 18:15:31 main-pi-v3.812 volumio[1037]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 15 18:15:31 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetState May 15 18:15:31 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 15 18:15:34 main-pi-v3.812 volumio-remote-updater[613]: No test mode May 15 18:15:34 main-pi-v3.812 volumio-remote-updater[613]: No alpha test mode May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 15 18:15:34 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioGetBrowseSources May 15 18:15:36 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 15 18:15:37 main-pi-v3.812 volumio[1037]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: Completed starting MyVolumio Plugin May 15 18:15:37 main-pi-v3.812 volumio[1037]: [Metrics] CommandRouter: 43s 708.53ms May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumiosetStartupVolume May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::Close All Modals sent May 15 18:15:37 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::Close All Modals sent May 15 18:15:38 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 15 18:15:38 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 15 18:15:38 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 15 18:15:39 main-pi-v3.812 volumiologrotate[594]: ls: cannot access '/var/log/samba/log.wb-MAIN': No such file or directory May 15 18:15:39 main-pi-v3.812 volumiologrotate[594]: ls: cannot access 'PI': No such file or directory May 15 18:15:39 main-pi-v3.812 volumiologrotate[594]: ls: cannot access '(V3.812)': No such file or directory May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioClearQueue May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::ClearQueue May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stPlaybackTimer May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::updateTrackBlock May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrackBlock May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::serviceStop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::serviceStop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::clearPlayQueue May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::saveQueue May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushQueue May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Handling event: musicStop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: May 15 18:15:43 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand stop took 46 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 1 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: May 15 18:15:43 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: May 15 18:15:43 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 6 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 3 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: 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":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: No code May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ------------------------------ 60ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 47 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 47 milliseconds May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: 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":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: No code May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: 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":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:15:43 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: No code May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ------------------------------ 136ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: ------------------------------ 136ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: stop PrevState: play May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [ASDebug] InitTimeout - Amp off in: 720 ms May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:43 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] Status changed: stop May 15 18:15:44 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: OFF May 15 18:15:44 main-pi-v3.812 volumio[1037]: info: BOOT COMPLETED May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: sdio ctrlframe tx failed err=-110 May 15 18:15:46 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_dpc: failed backplane access over SDIO, halting operation May 15 18:15:46 main-pi-v3.812 kernel: ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 May 15 18:15:46 main-pi-v3.812 kernel: ieee80211 phy0: brcmf_cfg80211_get_channel: chanspec failed (-110) May 15 18:15:48 main-pi-v3.812 ntpd[801]: Soliciting pool server 176.58.115.34 May 15 18:15:48 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 15 18:15:48 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 15 18:15:49 main-pi-v3.812 ntpd[801]: Soliciting pool server 162.159.200.123 May 15 18:15:49 main-pi-v3.812 ntpd[801]: Soliciting pool server 217.154.60.177 May 15 18:15:50 main-pi-v3.812 ntpd[801]: Soliciting pool server 82.219.4.30 May 15 18:15:50 main-pi-v3.812 ntpd[801]: Soliciting pool server 185.83.169.27 May 15 18:15:51 main-pi-v3.812 ntpd[801]: Soliciting pool server 90.155.12.14 May 15 18:15:51 main-pi-v3.812 ntpd[801]: Soliciting pool server 85.199.214.101 May 15 18:15:51 main-pi-v3.812 ntpd[801]: Soliciting pool server 139.162.219.252 May 15 18:15:51 main-pi-v3.812 ntpd[801]: Soliciting pool server 217.114.59.66 May 15 18:15:52 main-pi-v3.812 ntpd[801]: Soliciting pool server 139.143.5.31 May 15 18:15:52 main-pi-v3.812 ntpd[801]: Soliciting pool server 178.215.228.24 May 15 18:15:53 main-pi-v3.812 ntpd[801]: Soliciting pool server 83.151.207.133 May 15 18:15:53 main-pi-v3.812 ntpd[801]: Soliciting pool server 81.187.202.142 May 15 18:15:54 main-pi-v3.812 ntpd[801]: Soliciting pool server 93.93.131.118 May 15 18:15:54 main-pi-v3.812 ntpd[801]: Soliciting pool server 77.74.199.184 May 15 18:15:55 main-pi-v3.812 ntpd[801]: Soliciting pool server 2a01:7e00::f03c:91ff:fe96:f129 May 15 18:15:57 main-pi-v3.812 ntpd[801]: receive: Unexpected origin timestamp 0xebd09fcd.1d230bb1 does not match aorg 0000000000.00000000 from server@82.219.4.30 xmt 0xebd09fcd.e270c399 May 15 18:15:57 main-pi-v3.812 ntpd[801]: receive: Unexpected origin timestamp 0xebd09fcd.1d1c1694 does not match aorg 0000000000.00000000 from server@178.215.228.24 xmt 0xebd09fcd.e27efc8c May 15 18:16:01 main-pi-v3.812 volumio[1037]: info: [ASDebug] Port: 24 May 15 18:16:01 main-pi-v3.812 volumio[1037]: info: [ASDebug] Inverted: false May 15 18:16:01 main-pi-v3.812 volumio[1037]: info: [ASDebug] Delay: 720 May 15 18:16:02 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_bus_sleep: error while changing bus sleep state -110 May 15 18:16:02 main-pi-v3.812 kernel: brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame May 15 18:16:13 main-pi-v3.812 volumio[1037]: info: [GPIO_Control] GPIOs destroyed May 15 18:16:13 main-pi-v3.812 volumio[1037]: info: Disabling plugin gpio_control May 15 18:16:13 main-pi-v3.812 volumio[1037]: info: Done. May 15 18:16:23 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::getUIConfigOnPlugin May 15 18:16:23 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Getting UI config May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: CALLMETHOD: system_hardware gpio-buttons saveConfig [object Object] May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: gpio-buttons , saveConfig May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Destroying trigger 0 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Destroying trigger 1 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Destroying trigger 2 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Destroying trigger 3 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: Reading config and creating triggers... May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: playPause on pin 563 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: previous on pin 553 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: next on pin 558 May 15 18:16:27 main-pi-v3.812 volumio[1037]: info: GPIO-Buttons: shutdown on pin 546 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Preload queue cleared May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioAddQueueItems May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::addQueueItems May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::addQueueItems May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Preload queue cleared May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Adding Item to queue: music-library/NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Using cached record of: music-library/NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushQueue May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::saveQueue May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::updateTrackBlock May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrackBlock May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPlay May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::play index 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::stop May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::play index undefined May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::setConsumeUpdateService undefined May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::startPlaybackTimer May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::clearAddPlayTracks NAS/Folder 1; complete tracks/06 Brothers Johnson.flac May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand stop May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand stop took 5 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand clear May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand clear took 2 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand add "NAS/Folder 1; complete tracks/06 Brothers Johnson.flac" May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: error: updateQueue error: null May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 9ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand add "NAS/Folder 1; complete tracks/06 Brothers Johnson.flac" took 7 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 6ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 5ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces system playlist update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Ignoring MPD Status Update May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 13ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand play took 11 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 9ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 8ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: May 15 18:16:39 main-pi-v3.812 volumio[1037]: ---------------------------- MPD announces state update: player May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::getState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand status May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 9 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 9 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 6 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand status took 3 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseState May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: sendMpdCommand playlistinfo took 7 milliseconds May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: ControllerMpd::parseTrackInfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"643 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus stop May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"609 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"592 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ControllerMpd::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::servicePushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":308,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"592 Kbps","isStreaming":false,"title":"Brothers Johnson","artist":"Streetwave","album":"Doin' It - Connoisseur Soul Collection Volume 4","uri":"NAS/Folder 1; complete tracks/06 Brothers Johnson.flac","trackType":"flac"} May 15 18:16:39 main-pi-v3.812 volumio[1037]: verbose: CURRENT POSITION 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState stateService play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::syncState currentStatus play May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: Received an update from plugin. extracting info from payload May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreStateMachine::pushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CorePlayQueue::getTrack 0 May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: CoreCommandRouter::volumioPushState May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 79ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 135ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 131ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: ------------------------------ 129ms May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: [ASDebug] CurState: play PrevState: stop May 15 18:16:39 main-pi-v3.812 volumio[1037]: info: [ASDebug] Togle GPIO: ON May 15 18:16:39 main-pi-v3.812 volumio[1037]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 18:16:39 main-pi-v3.812 volumio[1037]: Error: EPERM: operation not permitted, write May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Object.writeSync (fs.js:711:3) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 15 18:16:39 main-pi-v3.812 volumio[1037]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { May 15 18:16:39 main-pi-v3.812 volumio[1037]: errno: -1, May 15 18:16:39 main-pi-v3.812 volumio[1037]: syscall: 'write', May 15 18:16:39 main-pi-v3.812 volumio[1037]: code: 'EPERM' May 15 18:16:39 main-pi-v3.812 volumio[1037]: } May 15 18:16:39 main-pi-v3.812 volumio[1037]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 15 18:16:40 main-pi-v3.812 sudo[1690]: volumio : unable to resolve host main-pi-v3.812 May 15 18:16:40 main-pi-v3.812 sudo[1690]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; May 15 18:16:40 main-pi-v3.812 sudo[1690]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-15 18:15 May 15 18:16:40 main-pi-v3.812 sudo[1690]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"