-- Logs begin at Thu 2019-02-14 02:12:00 PST, end at Sat 2025-12-20 19:13:58 PST. -- Dec 20 19:12:14 musicbox volumio[868]: info: Checking if install.sh is present Dec 20 19:12:14 musicbox volumio[868]: info: Executing install.sh Dec 20 19:12:14 musicbox sudo[16633]: pam_unix(sudo:auth): authentication failure; logname= uid=1000 euid=0 tty= ruser=volumio rhost= user=volumio Dec 20 19:12:16 musicbox sudo[16633]: pam_unix(sudo:auth): conversation failed Dec 20 19:12:16 musicbox sudo[16633]: pam_unix(sudo:auth): auth could not identify password for [volumio] Dec 20 19:12:16 musicbox sudo[16633]: volumio : 1 incorrect password attempt ; TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Dec 20 19:12:16 musicbox volumio[868]: info: Install script return the error Error: Command failed: echo volumio | sudo -S sh /data/plugins/music_service/spop/install.sh > /tmp/installog Dec 20 19:12:16 musicbox volumio[868]: [sudo] password for volumio: Sorry, try again. Dec 20 19:12:16 musicbox volumio[868]: [sudo] password for volumio: Dec 20 19:12:16 musicbox volumio[868]: sudo: no password was provided Dec 20 19:12:16 musicbox volumio[868]: sudo: 1 incorrect password attempt Dec 20 19:12:16 musicbox volumio[868]: info: An error occurred installing the plugin. Rolling back config Dec 20 19:12:16 musicbox volumio[868]: info: Plugin folders cleanup Dec 20 19:12:16 musicbox volumio[868]: info: Scanning into folder /volumio/app/plugins/ Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category audio_interface Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category miscellanea Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category music_service Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category plugins.json Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category system_controller Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category user_interface Dec 20 19:12:16 musicbox volumio[868]: info: Scanning into folder /data/plugins/ Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category music_service Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category system_hardware Dec 20 19:12:16 musicbox volumio[868]: info: Scanning category user_interface Dec 20 19:12:16 musicbox volumio[868]: info: Plugin folders cleanup completed Dec 20 19:12:16 musicbox volumio[868]: info: Error: Error Dec 20 19:12:16 musicbox volumio[868]: info: Error: Error Dec 20 19:12:16 musicbox volumio[868]: info: Folder /tmp/plugins removed Dec 20 19:12:16 musicbox volumio[868]: info: Folder /tmp/downloaded_plugin.zip removed Dec 20 19:12:16 musicbox volumio[868]: info: Folder /data/temp removed Dec 20 19:12:24 musicbox volumio[868]: info: CoreCommandRouter::volumioGetVisibleSources Dec 20 19:12:24 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 20 19:12:24 musicbox volumio[868]: info: CoreCommandRouter::volumioGetQueue Dec 20 19:12:24 musicbox volumio[868]: info: CoreStateMachine::getQueue Dec 20 19:12:24 musicbox volumio[868]: info: CorePlayQueue::getQueue Dec 20 19:12:39 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 20 19:12:39 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 20 19:12:54 musicbox volumio[868]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 20 19:12:54 musicbox volumio[868]: error: Cannot populate Spotify configuration: TypeError: Cannot read property 'bars' of undefined Dec 20 19:13:39 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 20 19:13:39 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 20 19:13:44 musicbox volumio[868]: info: Starting Uninstall of plugin music_service - spop Dec 20 19:13:44 musicbox volumio[868]: info: Uninstalling plugin spop Dec 20 19:13:44 musicbox volumio[868]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 20 19:13:44 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 20 19:13:44 musicbox volumio[868]: Cannot find translation for source YouTube2 Dec 20 19:13:44 musicbox volumio[868]: [SpotifyConnect] Closing metadata listener Dec 20 19:13:44 musicbox volumio[868]: [SpotifyConnect] Failed to close UDP Socket for Spotify Connect: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running Dec 20 19:13:44 musicbox sudo[16857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect.service Dec 20 19:13:44 musicbox volumio[868]: info: Disabling plugin spop Dec 20 19:13:44 musicbox sudo[16857]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 19:13:44 musicbox volumio[868]: info: Checking if uninstall.sh is present Dec 20 19:13:44 musicbox volumio[868]: info: Executing uninstall.sh Dec 20 19:13:44 musicbox sudo[16857]: pam_unix(sudo:session): session closed for user root Dec 20 19:13:44 musicbox volumio[868]: [SpotifyConnect] Vollibrespot Daemon service stoped! Dec 20 19:13:45 musicbox sudo[16861]: pam_unix(sudo:auth): authentication failure; logname= uid=1000 euid=0 tty= ruser=volumio rhost= user=volumio Dec 20 19:13:47 musicbox sudo[16861]: pam_unix(sudo:auth): conversation failed Dec 20 19:13:47 musicbox sudo[16861]: pam_unix(sudo:auth): auth could not identify password for [volumio] Dec 20 19:13:47 musicbox sudo[16861]: volumio : 1 incorrect password attempt ; TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/uninstall.sh Dec 20 19:13:47 musicbox volumio[868]: info: Uninstall script return the error Error: Command failed: echo volumio | sudo -S sh /data/plugins/music_service/spop/uninstall.sh > /tmp/installog Dec 20 19:13:47 musicbox volumio[868]: [sudo] password for volumio: Sorry, try again. Dec 20 19:13:47 musicbox volumio[868]: [sudo] password for volumio: Dec 20 19:13:47 musicbox volumio[868]: sudo: no password was provided Dec 20 19:13:47 musicbox volumio[868]: sudo: 1 incorrect password attempt Dec 20 19:13:53 musicbox volumio[868]: info: Enabling plugin spop Dec 20 19:13:53 musicbox volumio[868]: info: Loading plugin "spop"... Dec 20 19:13:53 musicbox volumio[868]: info: PLUGIN START: spop Dec 20 19:13:53 musicbox volumio[868]: info: Checking for old spotify connect plugin installed Dec 20 19:13:53 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 20 19:13:53 musicbox volumio[868]: [SpotifyConnect] Creating VLS config file Dec 20 19:13:53 musicbox volumio[868]: error: Failed to read template file: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/spop/volspotify.tmpl' Dec 20 19:13:53 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 20 19:13:53 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 20 19:13:53 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 20 19:13:53 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 20 19:13:53 musicbox volumio[868]: [SpotifyConnect] Starting metadata listener Dec 20 19:13:53 musicbox volumio[868]: (node:868) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'replace' of undefined Dec 20 19:13:53 musicbox volumio[868]: at ControllerSpotify.createConfigFile (/data/plugins/music_service/spop/index.js:2578:27) Dec 20 19:13:53 musicbox volumio[868]: at ControllerSpotify.init (/data/plugins/music_service/spop/index.js:2441:14) Dec 20 19:13:53 musicbox volumio[868]: at Promise._successFn (/data/plugins/music_service/spop/index.js:133:14) Dec 20 19:13:53 musicbox volumio[868]: at nextTickCallback (/data/plugins/music_service/spop/node_modules/kew/kew.js:47:28) Dec 20 19:13:53 musicbox volumio[868]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Dec 20 19:13:53 musicbox volumio[868]: (Use `node --trace-warnings ...` to show where the warning was created) Dec 20 19:13:53 musicbox volumio[868]: (node:868) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Dec 20 19:13:53 musicbox volumio[868]: (node:868) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Dec 20 19:13:53 musicbox sudo[16877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 20 19:13:53 musicbox sudo[16877]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 19:13:53 musicbox volumio[868]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 20 19:13:53 musicbox systemd[1]: Started Volspotconnect2 Daemon. Dec 20 19:13:53 musicbox sudo[16877]: pam_unix(sudo:session): session closed for user root Dec 20 19:13:53 musicbox volumio[16879]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 20 19:13:53 musicbox volumio[16879]: Reading Config from "/tmp/volspotify.toml" Dec 20 19:13:53 musicbox volumio[16879]: [Vollibrespot] : Using Alsa backend with device: volumio Dec 20 19:13:53 musicbox volumio[868]: [SpotifyConnect] Vollibrespot Daemon service started! Dec 20 19:13:53 musicbox volumio[868]: [Metrics] SpotifyConnect: 0s 254.38ms Dec 20 19:13:53 musicbox volumio[868]: info: Done. Dec 20 19:13:53 musicbox volumio[16879]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Dec 20 19:13:55 musicbox volumio[868]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Dec 20 19:13:55 musicbox volumio[868]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 20 19:13:55 musicbox volumio[868]: Cannot find translation for source YouTube2 Dec 20 19:13:55 musicbox volumio[868]: [SpotifyConnect] Closing metadata listener Dec 20 19:13:55 musicbox volumio[868]: info: Disabling plugin spop Dec 20 19:13:55 musicbox volumio[868]: info: Done. Dec 20 19:13:55 musicbox sudo[16882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect.service Dec 20 19:13:55 musicbox sudo[16882]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 20 19:13:55 musicbox systemd[1]: Stopping Volspotconnect2 Daemon... Dec 20 19:13:55 musicbox systemd[1]: volspotconnect.service: Main process exited, code=killed, status=15/TERM Dec 20 19:13:55 musicbox systemd[1]: volspotconnect.service: Succeeded. Dec 20 19:13:55 musicbox systemd[1]: Stopped Volspotconnect2 Daemon. Dec 20 19:13:55 musicbox sudo[16882]: pam_unix(sudo:session): session closed for user root Dec 20 19:13:55 musicbox volumio[868]: [SpotifyConnect] Vollibrespot Daemon service stoped! Dec 20 19:13:57 musicbox volumio[868]: info: Checking Spotify Web API Dec 20 19:13:57 musicbox volumio[868]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 20 19:13:57 musicbox volumio[868]: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running Dec 20 19:13:57 musicbox volumio[868]: at healthCheck (dgram.js:897:11) Dec 20 19:13:57 musicbox volumio[868]: at Socket.send (dgram.js:622:3) Dec 20 19:13:57 musicbox volumio[868]: at SpotConnEvents.sendmsg (/data/plugins/music_service/spop/SpotConnController.js:106:21) Dec 20 19:13:57 musicbox volumio[868]: at ControllerSpotify.checkWebApi (/data/plugins/music_service/spop/index.js:2354:23) Dec 20 19:13:57 musicbox volumio[868]: at Timeout._onTimeout (/data/plugins/music_service/spop/index.js:2446:18) Dec 20 19:13:57 musicbox volumio[868]: at listOnTimeout (internal/timers.js:554:17) Dec 20 19:13:57 musicbox volumio[868]: at processTimers (internal/timers.js:497:7) { Dec 20 19:13:57 musicbox volumio[868]: code: 'ERR_SOCKET_DGRAM_NOT_RUNNING' Dec 20 19:13:57 musicbox volumio[868]: } Dec 20 19:13:57 musicbox volumio[868]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 20 19:13:58 musicbox sudo[16896]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-20 19:12 Dec 20 19:13:58 musicbox sudo[16896]: 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"