-- Logs begin at Thu 2019-02-14 03:11:58 MST, end at Sun 2025-03-02 10:09:53 MST. -- Mar 02 10:08:04 volumio volumio[826]: info: CoreCommandRouter::volumioGetState Mar 02 10:08:07 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 10:08:07 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 02 10:08:17 volumio volumio[826]: info: Starting Uninstall of plugin music_service - dmd2_music Mar 02 10:08:17 volumio volumio[826]: info: Uninstalling plugin dmd2_music Mar 02 10:08:17 volumio volumio[826]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesdmd2_music Mar 02 10:08:17 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 10:08:17 volumio volumio[826]: Cannot find translation for source Calm Radio Mar 02 10:08:17 volumio volumio[826]: info: Stopping AccessToken refresher cron for DMD2 Music Mar 02 10:08:17 volumio volumio[826]: info: Disabling plugin dmd2_music Mar 02 10:08:17 volumio volumio[826]: info: Checking if uninstall.sh is present Mar 02 10:08:17 volumio volumio[826]: info: Executing uninstall.sh Mar 02 10:08:17 volumio sudo[2528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/dmd2_music/uninstall.sh Mar 02 10:08:17 volumio sudo[2528]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 10:08:17 volumio sudo[2528]: pam_unix(sudo:session): session closed for user root Mar 02 10:08:17 volumio volumio[826]: info: Uninstall script completed Mar 02 10:08:17 volumio volumio[826]: info: Removing plugin dmd2_music from configuration Mar 02 10:08:17 volumio volumio[826]: info: Successfully removed dmd2_music configuration files Mar 02 10:08:17 volumio volumio[826]: info: Plugin folders cleanup Mar 02 10:08:17 volumio volumio[826]: info: Scanning into folder /volumio/app/plugins/ Mar 02 10:08:17 volumio volumio[826]: info: Scanning category audio_interface Mar 02 10:08:17 volumio volumio[826]: info: Scanning category miscellanea Mar 02 10:08:17 volumio volumio[826]: info: Scanning category music_service Mar 02 10:08:17 volumio volumio[826]: info: Scanning category plugins.json Mar 02 10:08:17 volumio volumio[826]: info: Scanning category system_controller Mar 02 10:08:17 volumio volumio[826]: info: Scanning category user_interface Mar 02 10:08:17 volumio volumio[826]: info: Scanning into folder /data/plugins/ Mar 02 10:08:17 volumio volumio[826]: info: Scanning category music_service Mar 02 10:08:17 volumio volumio[826]: info: Cleaning folder for dmd2_music Mar 02 10:08:18 volumio volumio[826]: info: Scanning category system_controller Mar 02 10:08:18 volumio volumio[826]: info: Scanning category system_hardware Mar 02 10:08:18 volumio volumio[826]: info: Plugin folders cleanup completed Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 10:08:18 volumio volumio[826]: info: [{"prettyName":"Calm Radio","name":"calmradio","category":"music_service","version":"1.2.4","icon":"fa-heartbeat","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.3","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Amplifier Switch","name":"ampswitch","category":"system_controller","version":"0.2.1","icon":"fa-power-off","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Backup & Restore Data","name":"backup_restore","category":"system_controller","version":"0.7.4","icon":"fa-floppy-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"GPIO Control","name":"gpio_control","category":"system_hardware","version":"1.0.10","icon":"fa-microchip","isManuallyInstalled":false,"enabled":true,"active":true}] Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 02 10:08:18 volumio volumio[826]: info: Mar 02 10:08:18 volumio volumio[826]: ---------------------------- MPD announces system playlist update Mar 02 10:08:18 volumio volumio[826]: info: Ignoring MPD Status Update Mar 02 10:08:18 volumio volumio[826]: info: Mar 02 10:08:18 volumio volumio[826]: ---------------------------- MPD announces state update: player Mar 02 10:08:18 volumio volumio[826]: info: ControllerMpd::getState Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand status Mar 02 10:08:18 volumio volumio[826]: info: Mar 02 10:08:18 volumio volumio[826]: ---------------------------- MPD announces system playlist update Mar 02 10:08:18 volumio volumio[826]: info: Ignoring MPD Status Update Mar 02 10:08:18 volumio volumio[826]: info: Mar 02 10:08:18 volumio volumio[826]: ---------------------------- MPD announces state update: player Mar 02 10:08:18 volumio volumio[826]: info: ControllerMpd::getState Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand status Mar 02 10:08:18 volumio volumio[826]: info: ------------------------------ 8ms Mar 02 10:08:18 volumio volumio[826]: info: sendMpdCommand status took 8 milliseconds Mar 02 10:08:18 volumio volumio[826]: info: ------------------------------ 8ms Mar 02 10:08:18 volumio volumio[826]: info: sendMpdCommand status took 7 milliseconds Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::parseState Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::parseState Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 10:08:18 volumio volumio[826]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 02 10:08:18 volumio volumio[826]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 02 10:08:18 volumio volumio[826]: verbose: ControllerMpd::parseTrackInfo Mar 02 10:08:18 volumio volumio[826]: info: ControllerMpd::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::servicePushState Mar 02 10:08:18 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:08:18 volumio volumio[826]: verbose: STATE SERVICE {"status":"play","position":0,"seek":57474,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Paco de Lucia, Camaron De La Isla - Camaron de la Isla Con la Colaboracion Especial de Paco de Lucia - Al verte las flores lloran - Canastera","artist":"CALMRADIO.COM - Flamenco","album":null,"uri":"https://streams.calmradio.com/api/223/128/stream","trackType":""} Mar 02 10:08:18 volumio volumio[826]: verbose: CURRENT POSITION 0 Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::syncState stateService play Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::syncState currentStatus play Mar 02 10:08:18 volumio volumio[826]: info: Received an update from plugin. extracting info from payload Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:08:18 volumio volumio[826]: info: ControllerMpd::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::servicePushState Mar 02 10:08:18 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:08:18 volumio volumio[826]: verbose: STATE SERVICE {"status":"play","position":0,"seek":57474,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Paco de Lucia, Camaron De La Isla - Camaron de la Isla Con la Colaboracion Especial de Paco de Lucia - Al verte las flores lloran - Canastera","artist":"CALMRADIO.COM - Flamenco","album":null,"uri":"https://streams.calmradio.com/api/223/128/stream","trackType":""} Mar 02 10:08:18 volumio volumio[826]: verbose: CURRENT POSITION 0 Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::syncState stateService play Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::syncState currentStatus play Mar 02 10:08:18 volumio volumio[826]: info: Received an update from plugin. extracting info from payload Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:08:18 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:08:18 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:08:18 volumio volumio[826]: info: ------------------------------ 56ms Mar 02 10:08:18 volumio volumio[826]: info: ------------------------------ 55ms Mar 02 10:08:18 volumio volumio[826]: info: [ASDebug] CurState: play PrevState: play Mar 02 10:08:18 volumio volumio[826]: info: [ASDebug] CurState: play PrevState: play Mar 02 10:08:18 volumio volumio[826]: info: [ASDebug] CurState: play PrevState: play Mar 02 10:08:18 volumio volumio[826]: info: [GPIO_Control] Status changed: play Mar 02 10:08:18 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:08:18 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:08:18 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:08:18 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:08:25 volumio volumio[826]: info: Starting Uninstall of plugin music_service - spop Mar 02 10:08:25 volumio volumio[826]: info: Uninstalling plugin spop Mar 02 10:08:25 volumio go-librespot[1113]: time="2025-03-02T10:08:25-07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Mar 02 10:08:25 volumio volumio[826]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Mar 02 10:08:25 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 02 10:08:25 volumio volumio[826]: Cannot find translation for source Calm Radio Mar 02 10:08:25 volumio sudo[2574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Mar 02 10:08:25 volumio sudo[2574]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 10:08:25 volumio systemd[1]: Stopping go-librespot Daemon... Mar 02 10:08:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 02 10:08:25 volumio volumio[826]: info: Disabling plugin spop Mar 02 10:08:25 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Mar 02 10:08:25 volumio systemd[1]: Stopped go-librespot Daemon. Mar 02 10:08:25 volumio volumio[826]: info: Checking if uninstall.sh is present Mar 02 10:08:25 volumio volumio[826]: info: Connection to go-librespot Websocket closed Mar 02 10:08:25 volumio sudo[2574]: pam_unix(sudo:session): session closed for user root Mar 02 10:08:25 volumio volumio[826]: info: Executing uninstall.sh Mar 02 10:08:25 volumio sudo[2578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/uninstall.sh Mar 02 10:08:25 volumio sudo[2578]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 10:08:25 volumio sudo[2578]: pam_unix(sudo:session): session closed for user root Mar 02 10:08:25 volumio volumio[826]: info: Uninstall script completed Mar 02 10:08:25 volumio volumio[826]: info: Removing plugin spop from configuration Mar 02 10:08:25 volumio volumio[826]: info: Successfully removed spop configuration files Mar 02 10:08:25 volumio volumio[826]: info: Plugin folders cleanup Mar 02 10:08:25 volumio volumio[826]: info: Scanning into folder /volumio/app/plugins/ Mar 02 10:08:25 volumio volumio[826]: info: Scanning category audio_interface Mar 02 10:08:25 volumio volumio[826]: info: Scanning category miscellanea Mar 02 10:08:25 volumio volumio[826]: info: Scanning category music_service Mar 02 10:08:25 volumio volumio[826]: info: Scanning category plugins.json Mar 02 10:08:25 volumio volumio[826]: info: Scanning category system_controller Mar 02 10:08:25 volumio volumio[826]: info: Scanning category user_interface Mar 02 10:08:25 volumio volumio[826]: info: Scanning into folder /data/plugins/ Mar 02 10:08:25 volumio volumio[826]: info: Scanning category music_service Mar 02 10:08:25 volumio volumio[826]: info: Cleaning folder for spop Mar 02 10:08:25 volumio volumio[826]: info: Scanning category system_controller Mar 02 10:08:25 volumio volumio[826]: info: Scanning category system_hardware Mar 02 10:08:25 volumio volumio[826]: info: Plugin folders cleanup completed Mar 02 10:08:25 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 10:08:25 volumio volumio[826]: info: [{"prettyName":"Calm Radio","name":"calmradio","category":"music_service","version":"1.2.4","icon":"fa-heartbeat","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Amplifier Switch","name":"ampswitch","category":"system_controller","version":"0.2.1","icon":"fa-power-off","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Backup & Restore Data","name":"backup_restore","category":"system_controller","version":"0.7.4","icon":"fa-floppy-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"GPIO Control","name":"gpio_control","category":"system_hardware","version":"1.0.10","icon":"fa-microchip","isManuallyInstalled":false,"enabled":true,"active":true}] Mar 02 10:08:25 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 02 10:09:01 volumio volumio[826]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Mar 02 10:09:02 volumio volumio[826]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Mar 02 10:09:02 volumio volumio[826]: info: Folder /tmp/plugins removed Mar 02 10:09:02 volumio volumio[826]: info: Check plugin dependencies Mar 02 10:09:03 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 02 10:09:03 volumio volumio[826]: info: Checking if plugin already exists Mar 02 10:09:03 volumio volumio[826]: info: Rename folder Mar 02 10:09:03 volumio volumio[826]: info: Folder /tmp/downloaded_plugin.zip removed Mar 02 10:09:03 volumio volumio[826]: info: Move to category Mar 02 10:09:05 volumio volumio[826]: info: Checking if install.sh is present Mar 02 10:09:05 volumio volumio[826]: info: Executing install.sh Mar 02 10:09:05 volumio sudo[2672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Mar 02 10:09:05 volumio sudo[2672]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 10:09:05 volumio volumio[826]: info: Installing Go-librespot Mar 02 10:09:05 volumio volumio[826]: info: Checking old vollibrespot installs Mar 02 10:09:05 volumio systemd[1]: Reloading. Mar 02 10:09:05 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Mar 02 10:09:05 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Mar 02 10:09:05 volumio volumio[826]: info: Downloading daemon Mar 02 10:09:07 volumio volumio[826]: info: Creating directories Mar 02 10:09:07 volumio volumio[826]: info: Creating data directory Mar 02 10:09:07 volumio volumio[826]: info: Creating Start Script Mar 02 10:09:07 volumio systemd[1]: Reloading. Mar 02 10:09:08 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Mar 02 10:09:08 volumio volumio[826]: Plugin install end detected on script Mar 02 10:09:08 volumio sudo[2672]: pam_unix(sudo:session): session closed for user root Mar 02 10:09:08 volumio volumio[826]: info: Install script completed Mar 02 10:09:08 volumio volumio[826]: info: Adding reference to registry Mar 02 10:09:08 volumio volumio[826]: info: Done installing plugin. Mar 02 10:09:08 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 02 10:09:08 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 02 10:09:08 volumio volumio[826]: info: Folder /tmp/plugins removed Mar 02 10:09:08 volumio volumio[826]: info: Folder /tmp/downloaded_plugin.zip removed Mar 02 10:09:08 volumio volumio[826]: info: Folder /data/temp removed Mar 02 10:09:09 volumio volumio[826]: info: Enabling plugin spop Mar 02 10:09:09 volumio volumio[826]: info: Loading plugin "spop"... Mar 02 10:09:09 volumio volumio[826]: info: PLUGIN START: spop Mar 02 10:09:09 volumio volumio[826]: info: Creating Spotify config file Mar 02 10:09:09 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 02 10:09:09 volumio volumio[826]: info: Done. Mar 02 10:09:09 volumio volumio[826]: info: Spotify config file written Mar 02 10:09:09 volumio volumio[826]: info: No need to fix Spotify hosts Mar 02 10:09:09 volumio sudo[2737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 02 10:09:09 volumio sudo[2737]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 10:09:09 volumio systemd[1]: Started go-librespot Daemon. Mar 02 10:09:09 volumio go-librespot[2739]: go-librespot daemon starting... Mar 02 10:09:09 volumio sudo[2737]: pam_unix(sudo:session): session closed for user root Mar 02 10:09:09 volumio go-librespot[2739]: time="2025-03-02T10:09:09-07:00" level=info msg="running go-librespot 0.2.0" Mar 02 10:09:09 volumio go-librespot[2739]: time="2025-03-02T10:09:09-07:00" level=debug msg="no app state found" Mar 02 10:09:09 volumio go-librespot[2739]: time="2025-03-02T10:09:09-07:00" level=debug msg="stored credentials not found" Mar 02 10:09:09 volumio go-librespot[2739]: time="2025-03-02T10:09:09-07:00" level=info msg="generated new device id: 61e154df2c5d08ef83b917de63347ca1db79f412" Mar 02 10:09:09 volumio go-librespot[2739]: time="2025-03-02T10:09:09-07:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 02 10:09:10 volumio go-librespot[2739]: time="2025-03-02T10:09:10-07:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 02 10:09:10 volumio go-librespot[2739]: time="2025-03-02T10:09:10-07:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 02 10:09:10 volumio go-librespot[2739]: time="2025-03-02T10:09:10-07:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 02 10:09:10 volumio go-librespot[2739]: time="2025-03-02T10:09:10-07:00" level=info msg="zeroconf server listening on port 43307" Mar 02 10:09:12 volumio volumio[826]: info: go-librespot daemon successfully initialized Mar 02 10:09:15 volumio volumio[826]: info: Initializing connection to go-librespot Websocket Mar 02 10:09:15 volumio go-librespot[2739]: time="2025-03-02T10:09:15-07:00" level=debug msg="new websocket client" Mar 02 10:09:15 volumio volumio[826]: info: Connection to go-librespot Websocket established Mar 02 10:09:18 volumio volumio[826]: info: Getting Spotify volume Mar 02 10:09:18 volumio volumio[826]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 02 10:09:19 volumio volumio[826]: info: CoreCommandRouter::volumioGetState Mar 02 10:09:19 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:09:41 volumio volumio[826]: info: Starting Uninstall of plugin system_controller - ampswitch Mar 02 10:09:41 volumio volumio[826]: info: Uninstalling plugin ampswitch Mar 02 10:09:41 volumio volumio[826]: info: [ASDebug] Port: 24 Mar 02 10:09:41 volumio volumio[826]: info: [ASDebug] Inverted: false Mar 02 10:09:41 volumio volumio[826]: info: [ASDebug] Delay: 720 Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::volumioNext Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::next Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::stop Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::stPlaybackTimer Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::updateTrackBlock Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrackBlock Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::serviceStop Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::serviceStop Mar 02 10:09:52 volumio volumio[826]: info: [1740935392235] ControllerCalmRadio::stop Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand stop Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] CurState: stop PrevState: play Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Mar 02 10:09:52 volumio volumio[826]: info: [GPIO_Control] Status changed: stop Mar 02 10:09:52 volumio volumio[826]: info: [GPIO_Control] Handling event: musicStop Mar 02 10:09:52 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:09:52 volumio volumio[826]: info: Mar 02 10:09:52 volumio volumio[826]: ---------------------------- MPD announces state update: player Mar 02 10:09:52 volumio volumio[826]: info: sendMpdCommand stop took 16 milliseconds Mar 02 10:09:52 volumio volumio[826]: info: ControllerMpd::getState Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand status Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::play index undefined Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 1 Mar 02 10:09:52 volumio volumio[826]: info: Mar 02 10:09:52 volumio volumio[826]: ---------------------------- MPD announces state update: player Mar 02 10:09:52 volumio volumio[826]: info: ControllerMpd::getState Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand status Mar 02 10:09:52 volumio volumio[826]: info: sendMpdCommand status took 3 milliseconds Mar 02 10:09:52 volumio volumio[826]: info: sendMpdCommand status took 1 milliseconds Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::parseState Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::parseState Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 02 10:09:52 volumio volumio[826]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 02 10:09:52 volumio volumio[826]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::parseTrackInfo Mar 02 10:09:52 volumio volumio[826]: verbose: ControllerMpd::parseTrackInfo Mar 02 10:09:52 volumio volumio[826]: info: ControllerMpd::pushState Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::servicePushState Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current calmradio Received mpd Mar 02 10:09:52 volumio volumio[826]: info: ControllerMpd::pushState Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::servicePushState Mar 02 10:09:52 volumio volumio[826]: info: CoreStateMachine::pushState Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: CoreCommandRouter::volumioPushState Mar 02 10:09:52 volumio volumio[826]: info: CorePlayQueue::getTrack 0 Mar 02 10:09:52 volumio volumio[826]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current calmradio Received mpd Mar 02 10:09:52 volumio volumio[826]: info: ------------------------------ 21ms Mar 02 10:09:52 volumio volumio[826]: info: ------------------------------ 19ms Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] CurState: stop PrevState: play Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] CurState: stop PrevState: play Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Mar 02 10:09:52 volumio volumio[826]: info: [GPIO_Control] Status changed: stop Mar 02 10:09:52 volumio volumio[826]: info: [GPIO_Control] Status changed: stop Mar 02 10:09:52 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:09:52 volumio volumio[826]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 02 10:09:52 volumio volumio[826]: info: [ASDebug] Togle GPIO: OFF Mar 02 10:09:52 volumio volumio[826]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 10:09:52 volumio volumio[826]: Error: EBADF: bad file descriptor, write Mar 02 10:09:52 volumio volumio[826]: at Object.writeSync (fs.js:711:3) Mar 02 10:09:52 volumio volumio[826]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Mar 02 10:09:52 volumio volumio[826]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:221:23) Mar 02 10:09:52 volumio volumio[826]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Mar 02 10:09:52 volumio volumio[826]: at listOnTimeout (internal/timers.js:554:17) Mar 02 10:09:52 volumio volumio[826]: at processTimers (internal/timers.js:497:7) { Mar 02 10:09:52 volumio volumio[826]: errno: -9, Mar 02 10:09:52 volumio volumio[826]: syscall: 'write', Mar 02 10:09:52 volumio volumio[826]: code: 'EBADF' Mar 02 10:09:52 volumio volumio[826]: } Mar 02 10:09:52 volumio volumio[826]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 10:09:53 volumio sudo[2865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-02 10:08 Mar 02 10:09:53 volumio sudo[2865]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"