-- Logs begin at Thu 2025-02-27 20:49:04 JST, end at Mon 2025-03-10 17:18:52 JST. -- Mar 10 17:18:47 rivoyt ntpd[5942]: receive: Unexpected origin timestamp 0xeb6ad1b9.c45d3041 does not match aorg 0000000000.00000000 from server@45.159.48.231 xmt 0xeb791ee7.8983255e Mar 10 17:18:47 rivoyt ntpd[5942]: receive: Unexpected origin timestamp 0xeb6ad1b9.c45124d4 does not match aorg 0000000000.00000000 from server@108.160.132.224 xmt 0xeb791ee7.8a33063a Mar 10 17:18:47 rivoyt ntpd[5942]: receive: Unexpected origin timestamp 0xeb6ad1b9.c45a4bf0 does not match aorg 0000000000.00000000 from server@45.77.20.103 xmt 0xeb791ee7.8a0ad9d4 Mar 10 17:18:47 rivoyt systemd[1]: Starting Daily apt download activities... Mar 10 17:18:47 rivoyt systemd[1]: Starting Daily man-db regeneration... Mar 10 17:18:47 rivoyt systemd[1]: man-db.service: Succeeded. Mar 10 17:18:47 rivoyt systemd[1]: Started Daily man-db regeneration. Mar 10 17:18:47 rivoyt volumio[3183]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 10 17:18:47 rivoyt volumio[3183]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 10 17:18:47 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 10 17:18:47 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 10 17:18:47 rivoyt volumio[3183]: info: Starting MyVolumio Remote Streaming Endpoints Mar 10 17:18:47 rivoyt volumio[3183]: info: MyVolumio login type: Token Mar 10 17:18:47 rivoyt volumio[3183]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 10 17:18:47 rivoyt volumio[3183]: 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' Mar 10 17:18:48 rivoyt volumio[3183]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 10 17:18:48 rivoyt volumio[3183]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 10 17:18:48 rivoyt sudo[6045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 10 17:18:48 rivoyt sudo[6045]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:48 rivoyt sudo[6045]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:48 rivoyt sudo[6050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 10 17:18:48 rivoyt sudo[6050]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:48 rivoyt sudo[6050]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:48 rivoyt volumio[3183]: verbose: New Socket.io Connection to 192.168.2.116 from 192.168.2.110 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 34 Mar 10 17:18:48 rivoyt volumio[3183]: error: MyVolumio Custom Token format not valid, refreshing it Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::volumioGetVisibleSources Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Mar 10 17:18:48 rivoyt volumio[3183]: No protocol specified Mar 10 17:18:48 rivoyt volumio[3183]: xcb_connection_has_error() returned true Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Mar 10 17:18:48 rivoyt volumio[3183]: info: Received Get System Info Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 10 17:18:48 rivoyt volumio[3183]: info: Discovery: Getting this device information Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::volumioGetState Mar 10 17:18:48 rivoyt volumio[3183]: info: CorePlayQueue::getTrack 0 Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 10 17:18:48 rivoyt volumio-remote-updater[4396]: No test mode Mar 10 17:18:48 rivoyt volumio-remote-updater[4396]: No alpha test mode Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 10 17:18:48 rivoyt volumio[3183]: info: Retrieving Cloud Streaming UI Mar 10 17:18:48 rivoyt systemd[1]: apt-daily.service: Succeeded. Mar 10 17:18:48 rivoyt systemd[1]: Started Daily apt download activities. Mar 10 17:18:48 rivoyt systemd[1]: Starting Daily apt upgrade and clean activities... Mar 10 17:18:48 rivoyt volumio[3183]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 10 17:18:48 rivoyt volumio[3183]: info: Getting Tidal Cloud Configuration Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 10 17:18:48 rivoyt volumio[3183]: info: Getting Qobuz Cloud Configuration Mar 10 17:18:48 rivoyt volumio[3183]: info: Asking plugin for UI Config Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 10 17:18:48 rivoyt volumio[3183]: info: Getting Spotify Cloud Configuration Mar 10 17:18:48 rivoyt volumio[3183]: info: Asking plugin for UI Config Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 10 17:18:48 rivoyt volumio[3183]: info: Saving Spotify Acccount Mar 10 17:18:48 rivoyt volumio[3183]: info: Got it Mar 10 17:18:48 rivoyt volumio[3183]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 10 17:18:48 rivoyt volumio[3183]: info: Got Tidal Cloud Configuration Mar 10 17:18:48 rivoyt volumio[3183]: info: Got it Mar 10 17:18:48 rivoyt volumio[3183]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 10 17:18:49 rivoyt volumio[3183]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 10 17:18:49 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 10 17:18:49 rivoyt systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 10 17:18:49 rivoyt systemd[1]: Started Daily apt upgrade and clean activities. Mar 10 17:18:49 rivoyt volumio[3183]: info: MyVolumio login type: Token Mar 10 17:18:49 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Mar 10 17:18:49 rivoyt volumio[3183]: info: Loading i18n strings for locale ja Mar 10 17:18:49 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Mar 10 17:18:49 rivoyt volumio[3183]: info: Setting timezone to Asia/Tokyo Mar 10 17:18:49 rivoyt sudo[6135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Mar 10 17:18:49 rivoyt sudo[6135]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:49 rivoyt sudo[6135]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:49 rivoyt sudo[6138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Tokyo /etc/localtime Mar 10 17:18:49 rivoyt sudo[6138]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:49 rivoyt sudo[6138]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:49 rivoyt sudo[6141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Mar 10 17:18:49 rivoyt sudo[6141]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:49 rivoyt sudo[6141]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:49 rivoyt sudo[6144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Tokyo Mar 10 17:18:49 rivoyt sudo[6144]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:49 rivoyt dbus-daemon[2835]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.54' (uid=0 pid=6145 comm="/usr/bin/timedatectl set-timezone Asia/Tokyo " label="kernel") Mar 10 17:18:49 rivoyt systemd[1]: Starting Time & Date Service... Mar 10 17:18:50 rivoyt dbus-daemon[2835]: [system] Successfully activated service 'org.freedesktop.timedate1' Mar 10 17:18:50 rivoyt systemd[1]: Started Time & Date Service. Mar 10 17:18:50 rivoyt sudo[6144]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:50 rivoyt volumio[3183]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 10 17:18:50 rivoyt volumio[3183]: info: Fetching Streaming Services browse cache Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: A device disappeared from network Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: Device rivoyt disappeared from network Mar 10 17:18:50 rivoyt volumio[3183]: Updating browse sources language Mar 10 17:18:50 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: A device disappeared from network Mar 10 17:18:50 rivoyt volumio[3183]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: adding e35cf339-df4a-4ec9-ba75-014d6da34cc9 Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: Found device RivoYT Mar 10 17:18:50 rivoyt volumio[3183]: info: CoreCommandRouter::volumioGetState Mar 10 17:18:50 rivoyt volumio[3183]: info: CorePlayQueue::getTrack 0 Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: this is already registered, e35cf339-df4a-4ec9-ba75-014d6da34cc9 Mar 10 17:18:50 rivoyt volumio[3183]: info: Discovery: Found device RivoYT Mar 10 17:18:50 rivoyt volumio[3183]: info: CoreCommandRouter::volumioGetState Mar 10 17:18:50 rivoyt volumio[3183]: info: CorePlayQueue::getTrack 0 Mar 10 17:18:50 rivoyt volumio[3183]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 10 17:18:50 rivoyt volumio-time-update[2832]: volumio-time-update-util: Fetching time from Volumio... Mar 10 17:18:51 rivoyt volumio[3183]: info: MyVolumio token set successfully Mar 10 17:18:51 rivoyt volumio[3183]: info: MYVOLUMIO: Adding device Mar 10 17:18:51 rivoyt volumio[3183]: info: MYVOLUMIO: Evaluating Server Mar 10 17:18:51 rivoyt volumio-time-update[2832]: volumio-time-update-util: Setting system time to: 2025-03-10 17:18:51 Mar 10 17:18:51 rivoyt sudo[6161]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-03-10 17:18:51 Mar 10 17:18:51 rivoyt sudo[6161]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:51 rivoyt systemd-timedated[6147]: Changed local time to Mon Mar 10 17:18:51 2025 Mar 10 17:18:51 rivoyt sudo[6161]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:51 rivoyt volumio-time-update[2832]: volumio-time-update-util: System time updated successfully. Mar 10 17:18:51 rivoyt systemd[1]: Started Volumio Time Update Utility. Mar 10 17:18:51 rivoyt systemd[1]: Reached target Multi-User System. Mar 10 17:18:51 rivoyt systemd[1]: Reached target Graphical Interface. Mar 10 17:18:51 rivoyt systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 10 17:18:51 rivoyt systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 10 17:18:51 rivoyt systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 10 17:18:51 rivoyt systemd[1]: Startup finished in 12.973s (kernel) + 8min 46.390s (userspace) = 8min 59.363s. Mar 10 17:18:51 rivoyt volumio[3183]: info: MyVolumio status changed Mar 10 17:18:51 rivoyt volumio[3183]: info: Streaming services startup Mar 10 17:18:51 rivoyt volumio[3183]: info: Starting Streaming Daemon Mar 10 17:18:51 rivoyt volumio[3183]: info: Removing browser output: myVolumio user plan is not superstar Mar 10 17:18:51 rivoyt volumio[3183]: info: Removing audio output: Mar 10 17:18:51 rivoyt volumio[3183]: info: Stoppping Tunnel 1 Mar 10 17:18:51 rivoyt sudo[6179]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 10 17:18:51 rivoyt sudo[6179]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:51 rivoyt sudo[6179]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:51 rivoyt volumio[3183]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 10 17:18:51 rivoyt sudo[6182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 10 17:18:51 rivoyt volumio[3183]: error: Failed to ping endpoint eu2.myvolumio.org : unknown error Mar 10 17:18:51 rivoyt sudo[6182]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 10 17:18:51 rivoyt volumio[3183]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 10 17:18:51 rivoyt volumio[3183]: Error: Unable to resolve or reject the same promise twice Mar 10 17:18:51 rivoyt volumio[3183]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Mar 10 17:18:51 rivoyt volumio[3183]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32367) Mar 10 17:18:51 rivoyt volumio[3183]: at Socket.emit (events.js:400:28) Mar 10 17:18:51 rivoyt volumio[3183]: at addChunk (internal/streams/readable.js:293:12) Mar 10 17:18:51 rivoyt volumio[3183]: at readableAddChunk (internal/streams/readable.js:267:9) Mar 10 17:18:51 rivoyt volumio[3183]: at Socket.Readable.push (internal/streams/readable.js:206:10) Mar 10 17:18:51 rivoyt volumio[3183]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) Mar 10 17:18:51 rivoyt volumio[3183]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 10 17:18:51 rivoyt sudo[6182]: pam_unix(sudo:session): session closed for user root Mar 10 17:18:52 rivoyt sudo[6194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-10 17:17 Mar 10 17:18:52 rivoyt sudo[6194]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:49:04 PM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="65eb03fcbe62db7e7fbed9cd39ac44df"