-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sun 2026-01-25 11:10:22 CET. -- Jan 25 11:09:02 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 11:09:08 volumio go-librespot[10096]: time="2026-01-25T11:09:08+01:00" level=trace msg="sent dealer ping" Jan 25 11:09:08 volumio go-librespot[10096]: time="2026-01-25T11:09:08+01:00" level=trace msg="received dealer pong" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=trace msg="emitting websocket event: not_playing" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2ftsIBsirQonhMxCHsn52l" Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1DX949uWWpmTjT","uri":"spotify:track:4osP8M9dqqSdWlXFsRKZZ4","play_origin":"playlist"}} Jan 25 11:09:25 volumio volumio[9926]: error: Failed to decode event: not_playing Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=trace msg="emitting websocket event: will_play" Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1DX949uWWpmTjT","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","play_origin":"playlist"}} Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=info msg="loaded track \"The Lights of Macau\" (paused: false, position: 0ms, duration: 176145ms, prefetched: true)" uri="spotify:track:2ftsIBsirQonhMxCHsn52l" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=trace msg="scheduling prefetch in 146s" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=trace msg="emitting websocket event: metadata" Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","name":"The Lights of Macau","artist_names":["George Kuntz Four"],"album_name":"The Lights of Macau","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a0130a2a4317e42f048854dd","position":0,"duration":176145,"release_date":"year:2024 month:4 day:5","track_number":1,"disc_number":1}} Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 11:09:25 volumio go-librespot[10096]: time="2026-01-25T11:09:25+01:00" level=trace msg="emitting websocket event: playing" Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1DX949uWWpmTjT","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","resume":false,"play_origin":"playlist"}} Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: PUSH STATE SPOTIFY Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: {"status":"play","service":"spop","title":"The Lights of Macau","artist":"George Kuntz Four","album":"The Lights of Macau","albumart":"https://i.scdn.co/image/ab67616d00001e02a0130a2a4317e42f048854dd","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","trackType":"spotify","seek":0,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::servicePushState Jan 25 11:09:25 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 25 11:09:25 volumio volumio[9926]: info: [ASDebug] CurState: play PrevState: play Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: PUSH STATE SPOTIFY Jan 25 11:09:25 volumio volumio[9926]: SPOTIFY: {"status":"play","service":"spop","title":"The Lights of Macau","artist":"George Kuntz Four","album":"The Lights of Macau","albumart":"https://i.scdn.co/image/ab67616d00001e02a0130a2a4317e42f048854dd","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","trackType":"spotify","seek":1000,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::servicePushState Jan 25 11:09:25 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 11:09:25 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 25 11:09:25 volumio volumio[9926]: info: [ASDebug] CurState: play PrevState: play Jan 25 11:09:38 volumio go-librespot[10096]: time="2026-01-25T11:09:38+01:00" level=trace msg="sent dealer ping" Jan 25 11:09:38 volumio go-librespot[10096]: time="2026-01-25T11:09:38+01:00" level=trace msg="received dealer pong" Jan 25 11:09:39 volumio go-librespot[10096]: time="2026-01-25T11:09:39+01:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:2ftsIBsirQonhMxCHsn52l" Jan 25 11:09:41 volumio volumio[9926]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/mpdoutput/volumio/buster/armhf Jan 25 11:09:42 volumio volumio[9926]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/mpdoutput/volumio/buster/armhf Jan 25 11:09:42 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Jan 25 11:09:42 volumio sudo[17790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 11:09:42 volumio sudo[17790]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 25 11:09:42 volumio systemd[1]: Stopping Music Player Daemon... Jan 25 11:09:42 volumio systemd[1]: mpd.service: Succeeded. Jan 25 11:09:42 volumio systemd[1]: Stopped Music Player Daemon. Jan 25 11:09:42 volumio volumio[9926]: info: CoreCommandRouter::volumioGetState Jan 25 11:09:42 volumio volumio[9926]: info: Check plugin dependencies Jan 25 11:09:42 volumio systemd[1]: Starting Music Player Daemon... Jan 25 11:09:42 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 11:09:42 volumio volumio[9926]: info: Rename folder Jan 25 11:09:42 volumio sudo[17795]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 11:09:42 volumio sudo[17795]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 25 11:09:42 volumio sudo[17795]: pam_unix(sudo:session): session closed for user root Jan 25 11:09:42 volumio volumio[9926]: info: Move to category Jan 25 11:09:42 volumio volumio[9926]: info: Folder /tmp/downloaded_plugin.zip removed Jan 25 11:09:43 volumio volumio[9926]: info: Checking if install.sh is present Jan 25 11:09:43 volumio volumio[9926]: info: Executing install.sh Jan 25 11:09:43 volumio sudo[17809]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/audio_interface/mpdoutput/install.sh Jan 25 11:09:43 volumio sudo[17809]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 25 11:09:43 volumio sudo[17809]: pam_unix(sudo:session): session closed for user root Jan 25 11:09:43 volumio volumio[9926]: info: Install script completed Jan 25 11:09:43 volumio volumio[9926]: info: Done installing plugin. Jan 25 11:09:43 volumio volumio[9926]: info: Enabling plugin mpdoutput Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 11:09:43 volumio volumio[9926]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.62","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Mpd http & Icecast output","name":"mpdoutput","category":"audio_interface","version":"1.0.5","icon":"fa-music","isManuallyInstalled":false,"enabled":true,"active":false},{"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.3.4","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube Cast Receiver","name":"ytcr","category":"music_service","version":"1.2.0","icon":"fa-youtube","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":false}] Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 11:09:43 volumio volumio[9926]: info: Installing mpd http output Jan 25 11:09:43 volumio volumio[9926]: Plugin install end detected on script Jan 25 11:09:43 volumio volumio[9926]: info: Folder /tmp/plugins removed Jan 25 11:09:43 volumio volumio[9926]: info: Folder /tmp/downloaded_plugin.zip removed Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 11:09:43 volumio volumio[9926]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 11:09:43 volumio volumio[9926]: info: Folder /data/temp removed Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - Classic-FusionDsp Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - Classic-FusionDsp Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - Classic-FusionDsp Jan 25 11:09:43 volumio mpd[17802]: Jan 25 11:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 11:09:43 volumio systemd[1]: Started Music Player Daemon. Jan 25 11:09:43 volumio sudo[17790]: pam_unix(sudo:session): session closed for user root Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - Classic-FusionDsp Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Jan 25 11:09:43 volumio volumio[9926]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Jan 25 11:09:43 volumio volumio[9926]: error: updateQueue error: null Jan 25 11:09:46 volumio sudo[17814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 11:09:46 volumio sudo[17814]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 25 11:09:46 volumio systemd[1]: Stopping MPD Monitor Service... Jan 25 11:09:46 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Jan 25 11:09:46 volumio systemd[1]: mpd_monitor.service: Succeeded. Jan 25 11:09:46 volumio systemd[1]: Stopped MPD Monitor Service. Jan 25 11:09:46 volumio systemd[1]: Started MPD Monitor Service. Jan 25 11:09:46 volumio sudo[17814]: pam_unix(sudo:session): session closed for user root Jan 25 11:09:46 volumio mpd_monitor.sh[17816]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 11:09:46 volumio volumio[9926]: info: Successfully started MPD Monitor Jan 25 11:09:54 volumio go-librespot[10096]: time="2026-01-25T11:09:54+01:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:2ftsIBsirQonhMxCHsn52l" Jan 25 11:10:08 volumio go-librespot[10096]: time="2026-01-25T11:10:08+01:00" level=trace msg="sent dealer ping" Jan 25 11:10:08 volumio go-librespot[10096]: time="2026-01-25T11:10:08+01:00" level=trace msg="received dealer pong" Jan 25 11:10:09 volumio go-librespot[10096]: time="2026-01-25T11:10:09+01:00" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:2ftsIBsirQonhMxCHsn52l" Jan 25 11:10:09 volumio volumio[9926]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 11:10:21 volumio volumio[9926]: info: CALLMETHOD: audio_interface mpdoutput ehttpstream Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: mpdoutput , ehttpstream Jan 25 11:10:21 volumio volumio[9926]: info: mpdhttpout ---TRUE Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::volumioGetState Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::volumioPause Jan 25 11:10:21 volumio volumio[9926]: info: CoreStateMachine::pause Jan 25 11:10:21 volumio volumio[9926]: info: CoreStateMachine::stPlaybackTimer Jan 25 11:10:21 volumio volumio[9926]: info: CoreStateMachine::servicePause Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::servicePause Jan 25 11:10:21 volumio volumio[9926]: info: Spotify Received pause Jan 25 11:10:21 volumio volumio[9926]: SPOTIFY: SPOTIFY PAUSE Jan 25 11:10:21 volumio volumio[9926]: SPOTIFY: {"status":"play","title":"The Lights of Macau","artist":"George Kuntz Four","album":"The Lights of Macau","albumart":"https://i.scdn.co/image/ab67616d00001e02a0130a2a4317e42f048854dd","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","trackType":"spotify","codec":"ogg","seek":1000,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jan 25 11:10:21 volumio volumio[9926]: info: Sending Spotify command to local API: /player/pause Jan 25 11:10:21 volumio volumio[9926]: info: mpdhttpout --- Volumio set on pause Jan 25 11:10:21 volumio volumio[9926]: info: mpdhttpout ---Configuration successfully added to mpd.conf. Jan 25 11:10:21 volumio go-librespot[10096]: time="2026-01-25T11:10:21+01:00" level=debug msg="pause track at 55788ms" Jan 25 11:10:21 volumio go-librespot[10096]: time="2026-01-25T11:10:21+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 11:10:21 volumio go-librespot[10096]: time="2026-01-25T11:10:21+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 25 11:10:21 volumio go-librespot[10096]: time="2026-01-25T11:10:21+01:00" level=trace msg="emitting websocket event: paused" Jan 25 11:10:21 volumio volumio[9926]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:37i9dQZF1DX949uWWpmTjT","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","play_origin":"playlist"}} Jan 25 11:10:21 volumio volumio[9926]: SPOTIFY: PUSH STATE SPOTIFY Jan 25 11:10:21 volumio volumio[9926]: SPOTIFY: {"status":"pause","service":"spop","title":"The Lights of Macau","artist":"George Kuntz Four","album":"The Lights of Macau","albumart":"https://i.scdn.co/image/ab67616d00001e02a0130a2a4317e42f048854dd","uri":"spotify:track:2ftsIBsirQonhMxCHsn52l","trackType":"spotify","seek":56000,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::servicePushState Jan 25 11:10:21 volumio volumio[9926]: info: CoreStateMachine::pushState Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 11:10:21 volumio volumio[9926]: info: CoreCommandRouter::volumioPushState Jan 25 11:10:21 volumio volumio[9926]: info: [ASDebug] CurState: pause PrevState: play Jan 25 11:10:21 volumio volumio[9926]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Jan 25 11:10:22 volumio volumio[9926]: info: [ASDebug] Togle GPIO: OFF Jan 25 11:10:22 volumio volumio[9926]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 11:10:22 volumio volumio[9926]: Error: EBADF: bad file descriptor, write Jan 25 11:10:22 volumio volumio[9926]: at Object.writeSync (fs.js:711:3) Jan 25 11:10:22 volumio volumio[9926]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Jan 25 11:10:22 volumio volumio[9926]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:221:23) Jan 25 11:10:22 volumio volumio[9926]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Jan 25 11:10:22 volumio volumio[9926]: at listOnTimeout (internal/timers.js:554:17) Jan 25 11:10:22 volumio volumio[9926]: at processTimers (internal/timers.js:497:7) { Jan 25 11:10:22 volumio volumio[9926]: errno: -9, Jan 25 11:10:22 volumio volumio[9926]: syscall: 'write', Jan 25 11:10:22 volumio volumio[9926]: code: 'EBADF' Jan 25 11:10:22 volumio volumio[9926]: } Jan 25 11:10:22 volumio volumio[9926]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 11:10:22 volumio sudo[17950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-25 11:09 Jan 25 11:10:22 volumio sudo[17950]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"