-- Logs begin at Mon 2022-07-11 14:20:13 UTC, end at Tue 2024-10-29 18:53:01 UTC. -- Oct 29 18:52:00 volumio sudo[32319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 29 18:52:00 volumio sudo[32319]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:00 volumio sudo[32322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 29 18:52:00 volumio sudo[32319]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:00 volumio sudo[32322]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:00 volumio sudo[32322]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:00 volumio volumio[841]: verbose: New Socket.io Connection to 192.168.0.10 from 192.168.0.13 UA: okhttp/3.12.12 Total Clients: 9 Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::volumioGetVisibleSources Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:01 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 29 18:52:01 volumio volumio[841]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 29 18:52:01 volumio volumio[841]: info: Listing playlists Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 29 18:52:01 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 29 18:52:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 18:52:02 volumio volumio[841]: info: Received Get System Info Oct 29 18:52:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 18:52:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 18:52:02 volumio volumio[841]: info: Discovery: Getting this device information Oct 29 18:52:02 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:02 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:02 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 18:52:04 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 18:52:04 volumio volumio[841]: info: Received Get System Info Oct 29 18:52:04 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 18:52:04 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 18:52:04 volumio volumio[841]: info: Discovery: Getting this device information Oct 29 18:52:04 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:04 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:04 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 18:52:08 volumio volumio[841]: info: Tunnel connection is inactive, restarting it Oct 29 18:52:08 volumio volumio[841]: info: Starting Tunnel 1 Oct 29 18:52:08 volumio volumio[841]: info: Starting Tunnel Connection Checker Oct 29 18:52:08 volumio sudo[32348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 29 18:52:08 volumio sudo[32348]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:08 volumio autossh[32168]: received signal to exit (15) Oct 29 18:52:08 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... Oct 29 18:52:08 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Oct 29 18:52:08 volumio systemd[1]: sshtunnel.service: Succeeded. Oct 29 18:52:08 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. Oct 29 18:52:08 volumio volumio[841]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 29 18:52:08 volumio volumio[841]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 29 18:52:08 volumio systemd[1]: Started MyVolumio SSH Tunnel. Oct 29 18:52:08 volumio sudo[32348]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:08 volumio autossh[32356]: port set to 0, monitoring disabled Oct 29 18:52:08 volumio autossh[32356]: starting ssh (count 1) Oct 29 18:52:08 volumio autossh[32356]: ssh child pid is 32360 Oct 29 18:52:08 volumio volumio[841]: info: Remote SSH Started Oct 29 18:52:08 volumio volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Oct 29 18:52:08 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:08 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 29 18:52:20 volumio volumio[841]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 29 18:52:20 volumio volumio[841]: info: Error : CoreCommandRouter::executeOnPlugin: No method [retreiveBackendEventStates] in plugin my_volumio Oct 29 18:52:20 volumio volumio[841]: info: Received Get System Version Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 18:52:20 volumio volumio[841]: info: Received Get System Info Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 18:52:20 volumio volumio[841]: info: Discovery: Getting this device information Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:20 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:20 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 18:52:27 volumio volumiossh-tunnel[32354]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Oct 29 18:52:28 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:28 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:28 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:28 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 18:52:47 volumio volumio[841]: info: Discovery: Getting this device information Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:47 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 18:52:47 volumio volumio[841]: info: Discovery: Getting this device information Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:47 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:47 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 18:52:48 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 18:52:48 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 29 18:52:57 volumio volumio[841]: info: Enabling plugin spop Oct 29 18:52:57 volumio volumio[841]: info: Loading plugin "spop"... Oct 29 18:52:57 volumio volumio[841]: info: PLUGIN START: spop Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 29 18:52:57 volumio volumio[841]: [SpotifyConnect] Creating VLS config file Oct 29 18:52:57 volumio volumio[841]: error: Failed to read template file: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/spop/volspotify.tmpl' Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:52:57 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:52:57 volumio volumio[841]: [SpotifyConnect] Starting metadata listener Oct 29 18:52:57 volumio sudo[32369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Oct 29 18:52:57 volumio sudo[32369]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:57 volumio volumio[841]: (node:841) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'replace' of undefined Oct 29 18:52:57 volumio volumio[841]: at ControllerSpotify.createConfigFile (/data/plugins/music_service/spop/index.js:2524:27) Oct 29 18:52:57 volumio volumio[841]: at ControllerSpotify.init (/data/plugins/music_service/spop/index.js:2385:14) Oct 29 18:52:57 volumio volumio[841]: at ControllerSpotify.onStart (/data/plugins/music_service/spop/index.js:133:10) Oct 29 18:52:57 volumio volumio[841]: at PluginManager.startPlugin (/volumio/app/pluginmanager.js:431:30) Oct 29 18:52:57 volumio volumio[841]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 29 18:52:57 volumio volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Oct 29 18:52:57 volumio volumio[841]: (Use `node --trace-warnings ...` to show where the warning was created) Oct 29 18:52:57 volumio volumio[841]: (node:841) 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: 2) Oct 29 18:52:57 volumio volumio[841]: (node:841) [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. Oct 29 18:52:57 volumio sudo[32369]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:57 volumio sudo[32373]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Oct 29 18:52:57 volumio volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Oct 29 18:52:57 volumio sudo[32373]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:57 volumio systemd[1]: Started Volspotconnect2 Daemon. Oct 29 18:52:57 volumio sudo[32373]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:57 volumio volumio[32389]: /usr/lib/startconnect.sh: line 2: ./usr/bin/vollibrespot: No such file or directory Oct 29 18:52:57 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=127/n/a Oct 29 18:52:57 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Oct 29 18:52:57 volumio volumio[841]: [SpotifyConnect] Vollibrespot Daemon service started! Oct 29 18:52:57 volumio volumio[841]: [Metrics] SpotifyConnect: 0s 88.81ms Oct 29 18:52:57 volumio volumio[841]: info: Done. Oct 29 18:52:58 volumio volumio[841]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Oct 29 18:52:58 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 18:52:58 volumio volumio[841]: Cannot find translation for sourceMedia Servers Oct 29 18:52:58 volumio volumio[841]: [SpotifyConnect] Closing metadata listener Oct 29 18:52:58 volumio volumio[841]: info: Disabling plugin spop Oct 29 18:52:58 volumio volumio[841]: info: Done. Oct 29 18:52:58 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:58 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:58 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 29 18:52:58 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 29 18:52:58 volumio sudo[32396]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect.service Oct 29 18:52:58 volumio sudo[32396]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:52:58 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Oct 29 18:52:58 volumio sudo[32396]: pam_unix(sudo:session): session closed for user root Oct 29 18:52:58 volumio volumio[841]: [SpotifyConnect] Vollibrespot Daemon service stoped! Oct 29 18:53:00 volumio volumio[841]: info: Enabling plugin spop Oct 29 18:53:00 volumio volumio[841]: info: Loading plugin "spop"... Oct 29 18:53:00 volumio volumio[841]: info: PLUGIN START: spop Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 29 18:53:00 volumio volumio[841]: [SpotifyConnect] Creating VLS config file Oct 29 18:53:00 volumio volumio[841]: error: Failed to read template file: Error: ENOENT: no such file or directory, open '/data/plugins/music_service/spop/volspotify.tmpl' Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:53:00 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 18:53:00 volumio volumio[841]: [SpotifyConnect] Starting metadata listener Oct 29 18:53:00 volumio sudo[32406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Oct 29 18:53:00 volumio volumio[841]: (node:841) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'replace' of undefined Oct 29 18:53:00 volumio volumio[841]: at ControllerSpotify.createConfigFile (/data/plugins/music_service/spop/index.js:2524:27) Oct 29 18:53:00 volumio volumio[841]: at ControllerSpotify.init (/data/plugins/music_service/spop/index.js:2385:14) Oct 29 18:53:00 volumio volumio[841]: at ControllerSpotify.onStart (/data/plugins/music_service/spop/index.js:133:10) Oct 29 18:53:00 volumio volumio[841]: at PluginManager.startPlugin (/volumio/app/pluginmanager.js:431:30) Oct 29 18:53:00 volumio volumio[841]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 29 18:53:00 volumio volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Oct 29 18:53:00 volumio volumio[841]: (node:841) 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: 3) Oct 29 18:53:00 volumio volumio[841]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 9 Oct 29 18:53:00 volumio sudo[32406]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:53:00 volumio sudo[32410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Oct 29 18:53:00 volumio sudo[32406]: pam_unix(sudo:session): session closed for user root Oct 29 18:53:00 volumio sudo[32410]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 18:53:00 volumio systemd[1]: Started Volspotconnect2 Daemon. Oct 29 18:53:00 volumio sudo[32410]: pam_unix(sudo:session): session closed for user root Oct 29 18:53:00 volumio volumio[32422]: /usr/lib/startconnect.sh: line 2: ./usr/bin/vollibrespot: No such file or directory Oct 29 18:53:00 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=127/n/a Oct 29 18:53:00 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Oct 29 18:53:00 volumio volumio[841]: [SpotifyConnect] Vollibrespot Daemon service started! Oct 29 18:53:00 volumio volumio[841]: [Metrics] SpotifyConnect: 0s 83.34ms Oct 29 18:53:00 volumio volumio[841]: info: Done. Oct 29 18:53:01 volumio volumio[841]: info: Checking Spotify Web API Oct 29 18:53:01 volumio volumio[841]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 18:53:01 volumio volumio[841]: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running Oct 29 18:53:01 volumio volumio[841]: at new NodeError (internal/errors.js:322:7) Oct 29 18:53:01 volumio volumio[841]: at healthCheck (dgram.js:909:11) Oct 29 18:53:01 volumio volumio[841]: at Socket.send (dgram.js:643:3) Oct 29 18:53:01 volumio volumio[841]: at SpotConnEvents.sendmsg (/data/plugins/music_service/spop/SpotConnController.js:106:21) Oct 29 18:53:01 volumio volumio[841]: at ControllerSpotify.checkWebApi (/data/plugins/music_service/spop/index.js:2292:23) Oct 29 18:53:01 volumio volumio[841]: at Timeout._onTimeout (/data/plugins/music_service/spop/index.js:2390:18) Oct 29 18:53:01 volumio volumio[841]: at listOnTimeout (internal/timers.js:557:17) Oct 29 18:53:01 volumio volumio[841]: at processTimers (internal/timers.js:500:7) { Oct 29 18:53:01 volumio volumio[841]: code: 'ERR_SOCKET_DGRAM_NOT_RUNNING' Oct 29 18:53:01 volumio volumio[841]: } Oct 29 18:53:01 volumio volumio[841]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 18:53:01 volumio sudo[32438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-29 18:52 Oct 29 18:53:01 volumio sudo[32438]: 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="1f061e035f7cb2799b32d3520aa8e55cd07df6f9" VOLUMIO_FE_VERSION="9971a09df9c3edfdedf2ecf438999be8aba9db68" VOLUMIO_FE3_VERSION="3974def988c7b2392ddc85f9b8cb4692d5e8fda9" VOLUMIO_BE_VERSION="b3c53a818b9b3d0e5c13c9d346c4d613c4ca426f" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 11 Jul 2022 04:20:13 PM CEST" VOLUMIO_VERSION="3.324" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="af433e39d080d49c05b87a8feef2d795"