-- Logs begin at Thu 2024-08-22 15:13:49 BST, end at Thu 2024-08-22 15:41:56 BST. -- Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a7760164 does not match aorg 0000000000.00000000 from server@77.104.162.218 xmt 0xea71cc52.3e58a8be Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a7751944 does not match aorg 0000000000.00000000 from server@185.53.45.5 xmt 0xea71cc52.3df486f5 Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a76e286a does not match aorg 0000000000.00000000 from server@81.2.125.2 xmt 0xea71cc52.3ea808ed Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a7721241 does not match aorg 0000000000.00000000 from server@185.103.119.60 xmt 0xea71cc52.3f870dc7 Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a770e979 does not match aorg 0000000000.00000000 from server@81.187.90.2 xmt 0xea71cc52.3f6ea800 Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a77416f1 does not match aorg 0000000000.00000000 from server@195.171.43.10 xmt 0xea71cc52.4054d211 Aug 22 15:40:18 volumio ntpd[789]: receive: Unexpected origin timestamp 0xea71c66d.a77313b2 does not match aorg 0000000000.00000000 from server@85.199.214.102 xmt 0xea71cc52.40db999d Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:40:39 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:39 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:40:39 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.0.10:3000 from 192.168.0.11 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:39 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 22 15:40:39 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 22 15:40:44 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.0.10 from 192.168.0.11 UA: Mozilla/5.0 (Linux; Android 14; Pixel 6 Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.103 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 22 15:40:44 volumio volumio[823]: info: Received Get System Info Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:40:44 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:44 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetVisibleSources Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:44 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 22 15:40:44 volumio volumio[823]: info: Received Get System Info Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:40:44 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:44 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:44 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:44 volumio volumio[823]: info: Listing playlists Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::volumioGetQueue Aug 22 15:40:44 volumio volumio[823]: info: CoreStateMachine::getQueue Aug 22 15:40:44 volumio volumio[823]: info: CorePlayQueue::getQueue Aug 22 15:40:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 22 15:40:47 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 22 15:40:47 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 22 15:40:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:40:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:40:55 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:40:55 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:40:55 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:40:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:40:59 volumio volumio[823]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/buster/armhf Aug 22 15:41:01 volumio volumio[823]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/now_playing/volumio/buster/armhf Aug 22 15:41:01 volumio volumio[823]: info: Folder /tmp/plugins removed Aug 22 15:41:02 volumio volumio[823]: info: Check plugin dependencies Aug 22 15:41:02 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 22 15:41:02 volumio volumio[823]: info: Checking if plugin already exists Aug 22 15:41:02 volumio volumio[823]: info: Rename folder Aug 22 15:41:02 volumio volumio[823]: info: Folder /tmp/downloaded_plugin.zip removed Aug 22 15:41:05 volumio volumio[823]: info: Move to category Aug 22 15:41:20 volumio volumio[823]: info: Checking if install.sh is present Aug 22 15:41:20 volumio volumio[823]: info: Executing install.sh Aug 22 15:41:20 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.0.10 from 192.168.0.11 UA: Mozilla/5.0 (Linux; Android 14; Pixel 6 Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.103 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Aug 22 15:41:20 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.0.10 from 192.168.0.11 UA: Mozilla/5.0 (Linux; Android 14; Pixel 6 Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.103 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 22 15:41:20 volumio volumio[823]: verbose: New Socket.io Connection to 192.168.0.10 from 192.168.0.11 UA: Mozilla/5.0 (Linux; Android 14; Pixel 6 Build/AP2A.240605.024; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.103 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Aug 22 15:41:20 volumio sudo[1671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/user_interface/now_playing/install.sh Aug 22 15:41:20 volumio sudo[1671]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 22 15:41:20 volumio volumio[823]: info: Installing geo-tz node dependency Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::volumioGetVisibleSources Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:20 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 22 15:41:20 volumio volumio[823]: info: Received Get System Info Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:41:20 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:20 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:20 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:20 volumio volumio[823]: info: Listing playlists Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::volumioGetQueue Aug 22 15:41:20 volumio volumio[823]: info: CoreStateMachine::getQueue Aug 22 15:41:20 volumio volumio[823]: info: CorePlayQueue::getQueue Aug 22 15:41:20 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 22 15:41:21 volumio volumio[823]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 22 15:41:21 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:21 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:25 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:41:25 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:41:25 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:41:25 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:25 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:25 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:41:27 volumio volumio[823]: info: Enabling plugin now_playing Aug 22 15:41:27 volumio volumio[823]: info: Loading plugin "now_playing"... Aug 22 15:41:28 volumio volumio[823]: error: !!!! WARNING !!!! Aug 22 15:41:28 volumio volumio[823]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Aug 22 15:41:28 volumio volumio[823]: Require stack: Aug 22 15:41:28 volumio volumio[823]: - /data/plugins/user_interface/now_playing/dist/index.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/app/pluginmanager.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/app/index.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/index.js Aug 22 15:41:28 volumio volumio[823]: error: Stack trace: Error: Cannot find module 'geo-tz' Aug 22 15:41:28 volumio volumio[823]: Require stack: Aug 22 15:41:28 volumio volumio[823]: - /data/plugins/user_interface/now_playing/dist/index.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/app/pluginmanager.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/app/index.js Aug 22 15:41:28 volumio volumio[823]: - /volumio/index.js Aug 22 15:41:28 volumio volumio[823]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Aug 22 15:41:28 volumio volumio[823]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Aug 22 15:41:28 volumio volumio[823]: at Module.require (internal/modules/cjs/loader.js:952:19) Aug 22 15:41:28 volumio volumio[823]: at require (internal/modules/cjs/helpers.js:88:18) Aug 22 15:41:28 volumio volumio[823]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Aug 22 15:41:28 volumio volumio[823]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Aug 22 15:41:28 volumio volumio[823]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Aug 22 15:41:28 volumio volumio[823]: at Module.load (internal/modules/cjs/loader.js:928:32) Aug 22 15:41:28 volumio volumio[823]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Aug 22 15:41:28 volumio volumio[823]: at Module.require (internal/modules/cjs/loader.js:952:19) Aug 22 15:41:28 volumio volumio[823]: error: !!!! WARNING !!!! Aug 22 15:41:28 volumio volumio[823]: info: Done. Aug 22 15:41:34 volumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 22 15:41:36 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 22 15:41:36 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 22 15:41:43 volumio volumio[823]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 22 15:41:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 22 15:41:44 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 22 15:41:51 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 22 15:41:52 volumio go-librespot[1066]: time="2024-08-22T15:41:52+01:00" level=error msg="did not receive last pong from dealer, 34s passed" Aug 22 15:41:52 volumio go-librespot[1066]: time="2024-08-22T15:41:52+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusServiceRestart and reason = \"\"" Aug 22 15:41:52 volumio go-librespot[1066]: time="2024-08-22T15:41:52+01:00" level=debug msg="re-established dealer connection" Aug 22 15:41:52 volumio go-librespot[1066]: time="2024-08-22T15:41:52+01:00" level=debug msg="received connection id: MDQ0ZTBhMTgtNzAyZC00NDljLWE1MWEtZDljZGU4NmJlMmViK2RlYWxlcit0Y3A6Ly8wYWNiZDg2ZS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArMUM2NTFEMTNERjY4OEE1QkREOUU1OUM3REQyREQzNDFGMTcwOEE5QUY5MDYxMjIwNjA5MTQ0QzVCNUJGQTU0Ng==" Aug 22 15:41:52 volumio go-librespot[1066]: time="2024-08-22T15:41:52+01:00" level=debug msg="put connect state because NEW_DEVICE" Aug 22 15:41:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 22 15:41:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 22 15:41:55 volumio volumio[823]: info: Discovery: Getting this device information Aug 22 15:41:55 volumio volumio[823]: info: CoreCommandRouter::volumioGetState Aug 22 15:41:55 volumio volumio[823]: info: CorePlayQueue::getTrack 0 Aug 22 15:41:55 volumio volumio[823]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 22 15:41:55 volumio volumio[823]: info: + geo-tz@8.0.2 Aug 22 15:41:55 volumio volumio[823]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 22 15:41:55 volumio volumio[823]: TypeError: Cannot read property 'broadcastMessage' of null Aug 22 15:41:55 volumio volumio[823]: at /volumio/app/index.js:1515:32 Aug 22 15:41:55 volumio volumio[823]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Aug 22 15:41:55 volumio volumio[823]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Aug 22 15:41:55 volumio volumio[823]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1513:13) Aug 22 15:41:55 volumio volumio[823]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Aug 22 15:41:55 volumio volumio[823]: at Tail. (/volumio/app/pluginmanager.js:860:24) Aug 22 15:41:55 volumio volumio[823]: at Tail.emit (events.js:315:20) Aug 22 15:41:55 volumio volumio[823]: at ReadStream. (/volumio/node_modules/tail/lib/tail.js:51:33) Aug 22 15:41:55 volumio volumio[823]: at ReadStream.emit (events.js:315:20) Aug 22 15:41:55 volumio volumio[823]: at addChunk (internal/streams/readable.js:309:12) Aug 22 15:41:55 volumio volumio[823]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 22 15:41:56 volumio sudo[1708]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-22 15:40 Aug 22 15:41:56 volumio sudo[1708]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"