-- Logs begin at Thu 2019-02-14 17:11:58 +07, end at Sun 2025-02-23 20:42:28 +07. -- Feb 23 20:41:02 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 20:41:11 volumio volumio[1167]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 23 20:41:11 volumio volumio[1167]: info: Received Get System Version Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 20:41:11 volumio volumio[1167]: info: Received Get System Info Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 20:41:11 volumio volumio[1167]: info: Discovery: Getting this device information Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::volumioGetState Feb 23 20:41:11 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 20:41:12 volumio volumio[1167]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Feb 23 20:41:15 volumio volumio[1167]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf Feb 23 20:41:15 volumio volumio[1167]: info: Folder /tmp/plugins removed Feb 23 20:41:16 volumio volumio[1167]: info: Check plugin dependencies Feb 23 20:41:16 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 20:41:16 volumio volumio[1167]: info: Checking if plugin already exists Feb 23 20:41:16 volumio volumio[1167]: info: Rename folder Feb 23 20:41:16 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:41:16 volumio volumio[1167]: info: Move to category Feb 23 20:41:17 volumio volumio[1167]: info: Checking if install.sh is present Feb 23 20:41:17 volumio volumio[1167]: info: Executing install.sh Feb 23 20:41:17 volumio sudo[3280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Feb 23 20:41:17 volumio sudo[3280]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 20:41:17 volumio volumio[1167]: info: Installing Go-librespot Feb 23 20:41:17 volumio volumio[1167]: info: Checking old vollibrespot installs Feb 23 20:41:17 volumio systemd[1]: Reloading. Feb 23 20:41:17 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. Feb 23 20:41:18 volumio volumio[1167]: info: Downloading daemon Feb 23 20:41:31 volumio volumio[1167]: info: Creating directories Feb 23 20:41:31 volumio volumio[1167]: info: Creating data directory Feb 23 20:41:31 volumio volumio[1167]: info: Creating Start Script Feb 23 20:41:31 volumio systemd[1]: Reloading. Feb 23 20:41:31 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. Feb 23 20:41:32 volumio sudo[3280]: pam_unix(sudo:session): session closed for user root Feb 23 20:41:32 volumio volumio[1167]: Plugin install end detected on script Feb 23 20:41:32 volumio volumio[1167]: info: Install script completed Feb 23 20:41:32 volumio volumio[1167]: info: Adding reference to registry Feb 23 20:41:32 volumio volumio[1167]: info: Done installing plugin. Feb 23 20:41:32 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 20:41:32 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 20:41:32 volumio volumio[1167]: info: Folder /tmp/plugins removed Feb 23 20:41:32 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:41:32 volumio volumio[1167]: info: Folder /data/temp removed Feb 23 20:41:33 volumio volumio[1167]: info: Enabling plugin spop Feb 23 20:41:33 volumio volumio[1167]: info: Loading plugin "spop"... Feb 23 20:41:34 volumio volumio[1167]: info: PLUGIN START: spop Feb 23 20:41:34 volumio volumio[1167]: info: Creating Spotify config file Feb 23 20:41:34 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 20:41:34 volumio volumio[1167]: info: Done. Feb 23 20:41:34 volumio volumio[1167]: info: Spotify config file written Feb 23 20:41:34 volumio volumio[1167]: info: No need to fix Spotify hosts Feb 23 20:41:34 volumio sudo[3381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 20:41:34 volumio sudo[3381]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 20:41:34 volumio systemd[1]: Started go-librespot Daemon. Feb 23 20:41:34 volumio go-librespot[3383]: go-librespot daemon starting... Feb 23 20:41:34 volumio sudo[3381]: pam_unix(sudo:session): session closed for user root Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=info msg="running go-librespot 0.2.0" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=debug msg="no app state found" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=debug msg="stored credentials not found" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=info msg="generated new device id: 0f782e177102691bc28c35fda2d697d107264fae" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 20:41:34 volumio go-librespot[3383]: time="2025-02-23T20:41:34+07:00" level=info msg="zeroconf server listening on port 34677" Feb 23 20:41:37 volumio volumio[1167]: info: go-librespot daemon successfully initialized Feb 23 20:41:40 volumio volumio[1167]: info: Initializing connection to go-librespot Websocket Feb 23 20:41:40 volumio go-librespot[3383]: time="2025-02-23T20:41:40+07:00" level=debug msg="new websocket client" Feb 23 20:41:40 volumio volumio[1167]: info: Connection to go-librespot Websocket established Feb 23 20:41:41 volumio volumio[1167]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/autostart/volumio/buster/armhf Feb 23 20:41:43 volumio volumio[1167]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/autostart/volumio/buster/armhf Feb 23 20:41:43 volumio volumio[1167]: info: AutoStart - onStop Feb 23 20:41:43 volumio volumio[1167]: info: Check plugin dependencies Feb 23 20:41:43 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 20:41:43 volumio volumio[1167]: info: Rename folder Feb 23 20:41:43 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:41:43 volumio volumio[1167]: info: Move to category Feb 23 20:41:43 volumio volumio[1167]: info: Getting Spotify volume Feb 23 20:41:43 volumio volumio[1167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 23 20:41:43 volumio volumio[1167]: info: CoreCommandRouter::volumioGetState Feb 23 20:41:43 volumio volumio[1167]: SPOTIFY: RECEIVED VOLUMIO VOLUME 69 Feb 23 20:41:43 volumio volumio[1167]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 20:41:43 volumio volumio[1167]: SPOTIFY: VOLUMIO VOLUME 69 Feb 23 20:41:43 volumio volumio[1167]: info: Aligning Spotify Volume to Volumio Volume Feb 23 20:41:43 volumio volumio[1167]: info: CoreCommandRouter::volumioGetState Feb 23 20:41:43 volumio volumio[1167]: info: Setting Spotify Volume from Volumio: 69 Feb 23 20:41:43 volumio volumio[1167]: info: Checking if install.sh is present Feb 23 20:41:43 volumio volumio[1167]: info: Executing install.sh Feb 23 20:41:43 volumio sudo[3439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_controller/autostart/install.sh Feb 23 20:41:43 volumio sudo[3439]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 20:41:43 volumio sudo[3439]: pam_unix(sudo:session): session closed for user root Feb 23 20:41:43 volumio volumio[1167]: info: Installing autostart Dependencies - no special dependencies needed Feb 23 20:41:43 volumio volumio[1167]: Plugin install end detected on script Feb 23 20:41:43 volumio volumio[1167]: info: Install script completed Feb 23 20:41:43 volumio volumio[1167]: info: Done installing plugin. Feb 23 20:41:43 volumio volumio[1167]: info: Enabling plugin autostart Feb 23 20:41:43 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 20:41:43 volumio volumio[1167]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.54","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":false,"active":false},{"prettyName":"Mpd http & Icecast output","name":"mpdoutput","category":"audio_interface","version":"1.0.5","icon":"fa-music","isManuallyInstalled":false,"enabled":false,"active":false},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.1.3","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"1.3.3","icon":"fa-youtube-play","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":"AutoStart","name":"autostart","category":"system_controller","version":"3.0.4","icon":"fa-lightbulb-o","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Music Services Shield","name":"music_services_shield","category":"system_hardware","version":"1.3.1","icon":"fa-shield","isManuallyInstalled":false,"enabled":true,"active":true}] Feb 23 20:41:43 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 20:41:43 volumio volumio[1167]: info: Folder /tmp/plugins removed Feb 23 20:41:43 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:41:43 volumio volumio[1167]: info: Folder /data/temp removed Feb 23 20:41:45 volumio volumio[1167]: SPOTIFY: SETTING SPOTIFY VOLUME 69 Feb 23 20:41:45 volumio volumio[1167]: info: Sending Spotify command with payload to local API: /player/volume Feb 23 20:41:52 volumio volumio[1167]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/buster/armhf Feb 23 20:41:55 volumio volumio[1167]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/buster/armhf Feb 23 20:41:55 volumio volumio[1167]: info: Folder /tmp/plugins removed Feb 23 20:41:55 volumio volumio[1167]: info: Check plugin dependencies Feb 23 20:41:56 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 20:41:56 volumio volumio[1167]: info: Checking if plugin already exists Feb 23 20:41:56 volumio volumio[1167]: info: Rename folder Feb 23 20:41:56 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:41:56 volumio volumio[1167]: info: Move to category Feb 23 20:41:58 volumio volumio[1167]: info: Checking if install.sh is present Feb 23 20:41:58 volumio volumio[1167]: info: Executing install.sh Feb 23 20:41:58 volumio sudo[3514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/user_interface/now_playing/install.sh Feb 23 20:41:58 volumio sudo[3514]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 23 20:41:58 volumio volumio[1167]: info: Installing geo-tz node dependency Feb 23 20:42:06 volumio ntpd[819]: Soliciting pool server 115.165.161.155 Feb 23 20:42:17 volumio volumio[1167]: info: + point-in-polygon-hao@1.1.0 Feb 23 20:42:17 volumio volumio[1167]: info: added 1 package from 1 contributor and audited 329 packages in 5.004s Feb 23 20:42:17 volumio volumio[1167]: info: Feb 23 20:42:17 volumio volumio[1167]: info: 17 packages are looking for funding Feb 23 20:42:17 volumio volumio[1167]: info: run `npm fund` for details Feb 23 20:42:17 volumio volumio[1167]: info: Feb 23 20:42:17 volumio volumio[1167]: info: found 2 high severity vulnerabilities Feb 23 20:42:17 volumio volumio[1167]: info: run `npm audit fix` to fix them, or `npm audit` for details Feb 23 20:42:17 volumio volumio[1167]: info: Creating user directories (if not exist) Feb 23 20:42:17 volumio sudo[3514]: pam_unix(sudo:session): session closed for user root Feb 23 20:42:17 volumio volumio[1167]: info: Now Playing plugin installed Feb 23 20:42:17 volumio volumio[1167]: Plugin install end detected on script Feb 23 20:42:17 volumio volumio[1167]: info: Install script completed Feb 23 20:42:17 volumio volumio[1167]: info: Adding reference to registry Feb 23 20:42:17 volumio volumio[1167]: info: Done installing plugin. Feb 23 20:42:17 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 20:42:17 volumio volumio[1167]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 20:42:17 volumio volumio[1167]: info: Folder /tmp/plugins removed Feb 23 20:42:17 volumio volumio[1167]: info: Folder /tmp/downloaded_plugin.zip removed Feb 23 20:42:17 volumio volumio[1167]: info: Folder /data/temp removed Feb 23 20:42:18 volumio volumio[1167]: info: Enabling plugin now_playing Feb 23 20:42:18 volumio volumio[1167]: info: Loading plugin "now_playing"... Feb 23 20:42:18 volumio volumio[1167]: error: !!!! WARNING !!!! Feb 23 20:42:18 volumio volumio[1167]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Feb 23 20:42:18 volumio volumio[1167]: Require stack: Feb 23 20:42:18 volumio volumio[1167]: - /data/plugins/user_interface/now_playing/dist/index.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/app/pluginmanager.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/app/index.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/index.js Feb 23 20:42:18 volumio volumio[1167]: error: Stack trace: Error: Cannot find module 'geo-tz' Feb 23 20:42:18 volumio volumio[1167]: Require stack: Feb 23 20:42:18 volumio volumio[1167]: - /data/plugins/user_interface/now_playing/dist/index.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/app/pluginmanager.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/app/index.js Feb 23 20:42:18 volumio volumio[1167]: - /volumio/index.js Feb 23 20:42:18 volumio volumio[1167]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Feb 23 20:42:18 volumio volumio[1167]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Feb 23 20:42:18 volumio volumio[1167]: at Module.require (internal/modules/cjs/loader.js:952:19) Feb 23 20:42:18 volumio volumio[1167]: at require (internal/modules/cjs/helpers.js:88:18) Feb 23 20:42:18 volumio volumio[1167]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Feb 23 20:42:18 volumio volumio[1167]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Feb 23 20:42:18 volumio volumio[1167]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Feb 23 20:42:18 volumio volumio[1167]: at Module.load (internal/modules/cjs/loader.js:928:32) Feb 23 20:42:18 volumio volumio[1167]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Feb 23 20:42:18 volumio volumio[1167]: at Module.require (internal/modules/cjs/loader.js:952:19) Feb 23 20:42:18 volumio volumio[1167]: at require (internal/modules/cjs/helpers.js:88:18) Feb 23 20:42:18 volumio volumio[1167]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Feb 23 20:42:18 volumio volumio[1167]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Feb 23 20:42:18 volumio volumio[1167]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Feb 23 20:42:18 volumio volumio[1167]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Feb 23 20:42:18 volumio volumio[1167]: error: !!!! WARNING !!!! Feb 23 20:42:18 volumio volumio[1167]: info: Done. Feb 23 20:42:28 volumio volumio[1167]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/autostart/volumio/buster/armhf Feb 23 20:42:28 volumio volumio[1167]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 20:42:28 volumio volumio[1167]: TypeError: Cannot read property 'broadcastMessage' of null Feb 23 20:42:28 volumio volumio[1167]: at /volumio/app/index.js:1528:32 Feb 23 20:42:28 volumio volumio[1167]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Feb 23 20:42:28 volumio volumio[1167]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Feb 23 20:42:28 volumio volumio[1167]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1526:13) Feb 23 20:42:28 volumio volumio[1167]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Feb 23 20:42:28 volumio volumio[1167]: at PluginManager.updatePlugin (/volumio/app/pluginmanager.js:938:8) Feb 23 20:42:28 volumio volumio[1167]: at CoreCommandRouter.updatePlugin (/volumio/app/index.js:1461:22) Feb 23 20:42:28 volumio volumio[1167]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1229:45) Feb 23 20:42:28 volumio volumio[1167]: at Socket.emit (events.js:315:20) Feb 23 20:42:28 volumio volumio[1167]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Feb 23 20:42:28 volumio volumio[1167]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Feb 23 20:42:28 volumio volumio[1167]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 20:42:28 volumio sudo[3707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-23 20:41 Feb 23 20:42:28 volumio sudo[3707]: 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"