-- Logs begin at Mon 2024-09-09 10:16:06 JST, end at Mon 2024-09-09 10:19:42 JST. -- Sep 09 10:18:29 primo ntpd[4204]: Soliciting pool server 133.243.238.163 Sep 09 10:18:30 primo ntpd[4204]: Soliciting pool server 133.130.121.141 Sep 09 10:18:32 primo ntpd[4204]: Soliciting pool server 129.250.35.250 Sep 09 10:18:34 primo ntpd[4204]: Soliciting pool server 163.44.97.196 Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 09 10:18:57 primo volumio[3317]: info: Discovery: Getting this device information Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::volumioGetState Sep 09 10:18:57 primo volumio[3317]: info: CorePlayQueue::getTrack 0 Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 09 10:18:57 primo volumio[3317]: verbose: New Socket.io Connection to 192.168.1.11:3000 from 192.168.1.10 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::volumioGetState Sep 09 10:18:57 primo volumio[3317]: info: CorePlayQueue::getTrack 0 Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 09 10:18:57 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 09 10:19:18 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 09 10:19:18 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 09 10:19:18 primo volumio[3317]: info: Discovery: Getting this device information Sep 09 10:19:18 primo volumio[3317]: info: CoreCommandRouter::volumioGetState Sep 09 10:19:18 primo volumio[3317]: info: CorePlayQueue::getTrack 0 Sep 09 10:19:18 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 09 10:19:26 primo dhcpcd[3385]: eth0: offered 192.168.1.14 from 192.168.1.1 Sep 09 10:19:26 primo dhcpcd[3385]: eth0: probing address 192.168.1.14/24 Sep 09 10:19:32 primo dhcpcd[3385]: eth0: leased 192.168.1.14 for 14400 seconds Sep 09 10:19:32 primo dhcpcd[3385]: eth0: adding route to 192.168.1.0/24 Sep 09 10:19:32 primo dhcpcd[3385]: eth0: changing default route via 192.168.1.1 Sep 09 10:19:32 primo avahi-daemon[2836]: Registering new address record for 192.168.1.14 on eth0.IPv4. Sep 09 10:19:32 primo ntpd[4204]: ntpd exiting on signal 15 (Terminated) Sep 09 10:19:32 primo systemd[1]: Stopping Network Time Service... Sep 09 10:19:32 primo volumio[3317]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 09 10:19:32 primo systemd[1]: ntp.service: Succeeded. Sep 09 10:19:32 primo systemd[1]: Stopped Network Time Service. Sep 09 10:19:32 primo systemd[1]: Starting Network Time Service... Sep 09 10:19:32 primo volumio[3317]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 09 10:19:32 primo volumio[3317]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 09 10:19:32 primo ntpd[4384]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 09 10:19:32 primo ntpd[4384]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 09 10:19:32 primo systemd[1]: Started Network Time Service. Sep 09 10:19:32 primo ntpd[4401]: proto: precision = 1.250 usec (-20) Sep 09 10:19:32 primo ntpd[4401]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 09 10:19:32 primo ntpd[4401]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 09 10:19:32 primo ntpd[4401]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 622 days ago Sep 09 10:19:32 primo ntpd[4401]: Listen and drop on 0 v6wildcard [::]:123 Sep 09 10:19:32 primo ntpd[4401]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 09 10:19:32 primo ntpd[4401]: Listen normally on 2 lo 127.0.0.1:123 Sep 09 10:19:32 primo ntpd[4401]: Listen normally on 3 eth0 192.168.1.11:123 Sep 09 10:19:32 primo ntpd[4401]: Listen normally on 4 eth0 169.254.117.89:123 Sep 09 10:19:32 primo ntpd[4401]: Listen normally on 5 eth0 192.168.1.14:123 Sep 09 10:19:32 primo avahi-daemon[2836]: Withdrawing address record for 169.254.117.89 on eth0. Sep 09 10:19:32 primo ntpd[4401]: Listen normally on 6 wlan0 192.168.1.12:123 Sep 09 10:19:32 primo ntpd[4401]: Listening on routing socket on fd #23 for interface updates Sep 09 10:19:32 primo ntpd[4401]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 09 10:19:32 primo ntpd[4401]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Sep 09 10:19:32 primo dhcpcd[3385]: eth0: deleting route to 169.254.0.0/16 Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 09 10:19:33 primo volumio[3317]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 09 10:19:33 primo ntpd[4401]: Deleting interface #4 eth0, 169.254.117.89#123, interface stats: received=0, sent=0, dropped=0, active_time=1 secs Sep 09 10:19:33 primo ntpd[4401]: Soliciting pool server 202.182.111.234 Sep 09 10:19:34 primo ntpd[4401]: Soliciting pool server 172.105.204.105 Sep 09 10:19:34 primo ntpd[4401]: Soliciting pool server 202.181.103.212 Sep 09 10:19:34 primo volumio[3317]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 09 10:19:34 primo volumio[3317]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 09 10:19:34 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:34 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:35 primo volumio[3317]: info: Starting MyVolumio Remote Streaming Endpoints Sep 09 10:19:35 primo volumio[3317]: info: MyVolumio login type: Token Sep 09 10:19:35 primo volumio[3317]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 09 10:19:35 primo volumio[3317]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Sep 09 10:19:35 primo ntpd[4401]: Soliciting pool server 133.243.238.243 Sep 09 10:19:35 primo ntpd[4401]: Soliciting pool server 129.250.35.251 Sep 09 10:19:35 primo ntpd[4401]: Soliciting pool server 194.0.5.123 Sep 09 10:19:35 primo volumio[3317]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 09 10:19:36 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 09 10:19:36 primo volumio[3317]: info: Received Get System Info Sep 09 10:19:36 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 09 10:19:36 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 09 10:19:36 primo volumio[3317]: info: Discovery: Getting this device information Sep 09 10:19:36 primo volumio[3317]: info: CoreCommandRouter::volumioGetState Sep 09 10:19:36 primo volumio[3317]: info: CorePlayQueue::getTrack 0 Sep 09 10:19:36 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 09 10:19:36 primo ntpd[4401]: Soliciting pool server 160.16.113.133 Sep 09 10:19:36 primo ntpd[4401]: Soliciting pool server 163.44.97.196 Sep 09 10:19:36 primo ntpd[4401]: Soliciting pool server 45.77.20.103 Sep 09 10:19:36 primo ntpd[4401]: Soliciting pool server 133.243.238.163 Sep 09 10:19:36 primo volumio[3317]: info: MyVolumio token set successfully Sep 09 10:19:36 primo volumio[3317]: info: MYVOLUMIO: Adding device Sep 09 10:19:36 primo volumio[3317]: info: MYVOLUMIO: Evaluating Server Sep 09 10:19:37 primo volumio[3317]: info: MyVolumio status changed Sep 09 10:19:37 primo volumio[3317]: info: Streaming services startup Sep 09 10:19:37 primo volumio[3317]: info: Starting Streaming Daemon Sep 09 10:19:37 primo volumio[3317]: info: Removing browser output: myVolumio user plan is not superstar Sep 09 10:19:37 primo volumio[3317]: info: Removing audio output: Sep 09 10:19:37 primo volumio[3317]: info: Stoppping Tunnel 1 Sep 09 10:19:37 primo sudo[4467]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 09 10:19:37 primo sudo[4467]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 10:19:37 primo sudo[4467]: pam_unix(sudo:session): session closed for user root Sep 09 10:19:37 primo ntpd[4401]: Soliciting pool server 167.179.119.205 Sep 09 10:19:37 primo ntpd[4401]: Soliciting pool server 129.250.35.250 Sep 09 10:19:37 primo ntpd[4401]: Soliciting pool server 162.159.200.1 Sep 09 10:19:37 primo sudo[4470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Sep 09 10:19:37 primo sudo[4470]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 09 10:19:37 primo volumio[3317]: error: Cannot start Volumio Streaming Daemon Sep 09 10:19:37 primo volumio[3317]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 09 10:19:37 primo volumio[3317]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 09 10:19:37 primo sudo[4470]: pam_unix(sudo:session): session closed for user root Sep 09 10:19:37 primo volumio[3317]: info: Remote SSH Stopped Sep 09 10:19:37 primo volumio[3317]: info: Setting Geolocation for MyVolumio to as1 Sep 09 10:19:37 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:37 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:37 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:38 primo volumio[3317]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 09 10:19:38 primo ntpd[4401]: Soliciting pool server 162.159.200.123 Sep 09 10:19:38 primo ntpd[4401]: Soliciting pool server 45.76.211.39 Sep 09 10:19:38 primo volumio[3317]: info: Updating MyVolumio device info Sep 09 10:19:38 primo volumio[3317]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 09 10:19:38 primo ntpd[4401]: Soliciting pool server 133.130.121.141 Sep 09 10:19:39 primo volumio[3317]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 09 10:19:39 primo ntpd[4401]: Soliciting pool server 108.160.132.224 Sep 09 10:19:39 primo ntpd[4401]: Soliciting pool server 2400:8902::f03c:91ff:fe50:f5f0 Sep 09 10:19:42 primo volumio[3317]: info: MYVOLUMIO: Adding device Sep 09 10:19:42 primo volumio[3317]: info: MYVOLUMIO: Evaluating Server Sep 09 10:19:41 primo ntpd[4401]: receive: Unexpected origin timestamp 0xea88cbae.99a8e0e7 does not match aorg 0000000000.00000000 from server@129.250.35.251 xmt 0xea88cbad.25d6a6cb Sep 09 10:19:41 primo ntpd[4401]: receive: Unexpected origin timestamp 0xea88cbae.99ab193f does not match aorg 0000000000.00000000 from server@172.105.204.105 xmt 0xea88cbad.25ae5eee Sep 09 10:19:41 primo ntpd[4401]: receive: Unexpected origin timestamp 0xea88cbae.99a69ed9 does not match aorg 0000000000.00000000 from server@163.44.97.196 xmt 0xea88cbad.2774e238 Sep 09 10:19:41 primo volumio[3317]: error: Failed to ping endpoint eu3.myvolumio.org : unknown error Sep 09 10:19:41 primo volumio[3317]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 10:19:41 primo volumio[3317]: Error: Unable to resolve or reject the same promise twice Sep 09 10:19:41 primo volumio[3317]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Sep 09 10:19:41 primo volumio[3317]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Sep 09 10:19:41 primo volumio[3317]: at Socket.emit (events.js:400:28) Sep 09 10:19:41 primo volumio[3317]: at addChunk (internal/streams/readable.js:293:12) Sep 09 10:19:41 primo volumio[3317]: at readableAddChunk (internal/streams/readable.js:267:9) Sep 09 10:19:41 primo volumio[3317]: at Socket.Readable.push (internal/streams/readable.js:206:10) Sep 09 10:19:41 primo volumio[3317]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Sep 09 10:19:41 primo volumio[3317]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 09 10:19:42 primo sudo[4499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-09 10:18 Sep 09 10:19:42 primo sudo[4499]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 08:03:03 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="c337e843637aa9ec6cbebba26aa72859"