-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Fri 2026-03-27 14:38:51 EDT. -- Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 27 14:37:06 minidsp-shd volumio[750]: xcb_connection_has_error() returned true Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 27 14:37:06 minidsp-shd volumio[750]: xcb_connection_has_error() returned true Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Mar 27 14:37:06 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 27 14:37:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:37:18-04:00" level=trace msg="sent dealer ping" Mar 27 14:37:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:37:18-04:00" level=trace msg="received dealer pong" Mar 27 14:37:41 minidsp-shd volumio[750]: info: CALLMETHOD: audio_interface alsa_controller saveResamplingOpts [object Object] Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveResamplingOpts Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: mpd , saveResampleOptions Mar 27 14:37:41 minidsp-shd sudo[1804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 14:37:41 minidsp-shd sudo[1804]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 14:37:41 minidsp-shd sudo[1804]: pam_unix(sudo:session): session closed for user root Mar 27 14:37:41 minidsp-shd sudo[1807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 14:37:41 minidsp-shd sudo[1807]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 14:37:41 minidsp-shd volumio[750]: info: MPD Permissions set Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd systemd[1]: Stopping Music Player Daemon... Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 14:37:41 minidsp-shd volumio[750]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 27 14:37:41 minidsp-shd volumio[750]: info: CoreCommandRouter::volumioGetState Mar 27 14:37:41 minidsp-shd systemd[1]: mpd.service: Succeeded. Mar 27 14:37:41 minidsp-shd systemd[1]: Stopped Music Player Daemon. Mar 27 14:37:41 minidsp-shd volumio[750]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 27 14:37:41 minidsp-shd systemd[1]: Starting Music Player Daemon... Mar 27 14:37:41 minidsp-shd volumio[750]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 27 14:37:41 minidsp-shd sudo[1815]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 14:37:41 minidsp-shd sudo[1815]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 27 14:37:42 minidsp-shd sudo[1815]: pam_unix(sudo:session): session closed for user root Mar 27 14:37:44 minidsp-shd mpd[1817]: Mar 27 14:37 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 27 14:37:44 minidsp-shd systemd[1]: Started Music Player Daemon. Mar 27 14:37:44 minidsp-shd sudo[1807]: pam_unix(sudo:session): session closed for user root Mar 27 14:37:44 minidsp-shd volumio[750]: error: updateQueue error: null Mar 27 14:37:48 minidsp-shd go-librespot[1168]: time="2026-03-27T14:37:48-04:00" level=trace msg="sent dealer ping" Mar 27 14:37:48 minidsp-shd go-librespot[1168]: time="2026-03-27T14:37:48-04:00" level=trace msg="received dealer pong" Mar 27 14:38:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:18-04:00" level=trace msg="received accesspoint ping" Mar 27 14:38:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:18-04:00" level=trace msg="received accesspoint pong ack" Mar 27 14:38:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:18-04:00" level=trace msg="sent dealer ping" Mar 27 14:38:18 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:18-04:00" level=trace msg="received dealer pong" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=debug msg="handling skip_next player command from 72a042d7a4aef05ee842892091954036f07d4ac1" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4fYgRHmXTFDUx5OfbK17ks" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=trace msg="emitting websocket event: will_play" Mar 27 14:38:28 minidsp-shd volumio[750]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4fYgRHmXTFDUx5OfbK17ks","play_origin":"playlist"}} Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=warning msg="original track has no formats, alternatives have a total of 0" uri="spotify:track:4fYgRHmXTFDUx5OfbK17ks" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=info msg="skipping unplayable media: spotify:track:4fYgRHmXTFDUx5OfbK17ks" error="failed creating stream for spotify:track:4fYgRHmXTFDUx5OfbK17ks: no supported formats" Mar 27 14:38:28 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:28-04:00" level=warning msg="failed handling dealer request" error="failed skipping to next track: failed creating stream for spotify:track:4fYgRHmXTFDUx5OfbK17ks: no supported formats" Mar 27 14:38:30 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:30-04:00" level=debug msg="handling pause player command from 72a042d7a4aef05ee842892091954036f07d4ac1" Mar 27 14:38:30 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:30-04:00" level=warning msg="failed handling dealer request" error="no primary stream" Mar 27 14:38:33 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:33-04:00" level=debug msg="handling resume player command from 72a042d7a4aef05ee842892091954036f07d4ac1" Mar 27 14:38:33 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:33-04:00" level=warning msg="failed handling dealer request" error="no primary stream" Mar 27 14:38:44 minidsp-shd volumio[750]: info: CoreCommandRouter::volumioGetQueue Mar 27 14:38:44 minidsp-shd volumio[750]: info: CoreStateMachine::getQueue Mar 27 14:38:44 minidsp-shd volumio[750]: info: CorePlayQueue::getQueue Mar 27 14:38:48 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:48-04:00" level=trace msg="sent dealer ping" Mar 27 14:38:48 minidsp-shd go-librespot[1168]: time="2026-03-27T14:38:48-04:00" level=trace msg="received dealer pong" Mar 27 14:38:50 minidsp-shd volumio[750]: info: CoreCommandRouter::volumioSeek Mar 27 14:38:50 minidsp-shd volumio[750]: info: CoreStateMachine::seek Mar 27 14:38:50 minidsp-shd volumio[750]: info: [1774636730228] inputs::seek to 0 Mar 27 14:38:50 minidsp-shd volumio[750]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 14:38:50 minidsp-shd volumio[750]: TypeError: this.sendSpopCommand is not a function Mar 27 14:38:50 minidsp-shd volumio[750]: at inputs.seek (/volumio/app/plugins/music_service/inputs/inputs_real:1:2486) Mar 27 14:38:50 minidsp-shd volumio[750]: at CoreStateMachine.seek (/volumio/app/statemachine.js:1098:20) Mar 27 14:38:50 minidsp-shd volumio[750]: at CoreCommandRouter.volumioSeek (/volumio/app/index.js:1446:28) Mar 27 14:38:50 minidsp-shd volumio[750]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:177:33) Mar 27 14:38:50 minidsp-shd volumio[750]: at Socket.emit (events.js:400:28) Mar 27 14:38:50 minidsp-shd volumio[750]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 27 14:38:50 minidsp-shd volumio[750]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Mar 27 14:38:50 minidsp-shd volumio[750]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 14:38:51 minidsp-shd sudo[1968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-27 14:37 Mar 27 14:38:51 minidsp-shd sudo[1968]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 11:08:05 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="2435172a9e07e22ce77410ca4817b0fa"