-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Fri 2024-11-29 15:01:19 CET. -- Nov 29 15:01:18 volumio systemd-timedated[2145]: Changed local time to Fri Nov 29 15:01:18 2024 Nov 29 15:01:18 volumio sudo[2139]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:18 volumio systemd[1]: Starting Daily man-db regeneration... Nov 29 15:01:18 volumio systemd[1]: Starting Daily apt download activities... Nov 29 15:01:18 volumio volumio-time-update[553]: volumio-time-update-util: System time updated successfully. Nov 29 15:01:18 volumio systemd[1]: Started Volumio Time Update Utility. Nov 29 15:01:18 volumio systemd[1]: Reached target Multi-User System. Nov 29 15:01:18 volumio systemd[1]: Reached target Graphical Interface. Nov 29 15:01:18 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 29 15:01:18 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 29 15:01:18 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 29 15:01:18 volumio systemd[1]: man-db.service: Succeeded. Nov 29 15:01:18 volumio systemd[1]: Started Daily man-db regeneration. Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="zeroconf server listening on port 45187" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="obtained new client token: AAAcP1+SN4heKfX40mY6OIyyBLmTJIuKIzGMxuQEG05wsgdMZLd3BPA4Rcj96cvhvRAw9Qu7cO+Uxne3tgicyibP89vdgPhQVVkuoBQ3365s6PCmWoa5fljotiRIKej+Ani00yQF1mpnlEiQBVe4iw1KLU4zwzx+iht2GGoxOYG29Q2jMEeVbmnngTikT5chC1IlIMMRCw+YA5sc/u1gRvbSIO5ppo0XuM8ehQ+kPW1rXc/XFLpzCpT8miCq4ro=" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Nov 29 15:01:18 volumio go-librespot[1895]: time="2024-11-29T15:01:18+01:00" level=debug msg="completed keyexchange" Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Nov 29 15:01:19 volumio sudo[2176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Nov 29 15:01:19 volumio sudo[2176]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 15:01:19 volumio sudo[2176]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:19 volumio volumio[1262]: info: MRS: MultiRoom plugin initialized Nov 29 15:01:19 volumio volumio[1262]: info: MRS: STOPPING SNAPCLIENT Nov 29 15:01:19 volumio volumio[1262]: info: MRS: Snap server stop Nov 29 15:01:19 volumio volumio[1262]: info: MRS: STOPPING volumioStreaming Nov 29 15:01:19 volumio sudo[2199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Nov 29 15:01:19 volumio sudo[2199]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 15:01:19 volumio sudo[2205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Nov 29 15:01:19 volumio sudo[2213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Nov 29 15:01:19 volumio sudo[2214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Nov 29 15:01:19 volumio sudo[2213]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 15:01:19 volumio sudo[2205]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 15:01:19 volumio sudo[2214]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 29 15:01:19 volumio sudo[2199]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:19 volumio sudo[2214]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Nov 29 15:01:19 volumio sudo[2205]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:19 volumio sudo[2213]: pam_unix(sudo:session): session closed for user root Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Nov 29 15:01:19 volumio volumio[1262]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Nov 29 15:01:19 volumio volumio[1262]: info: Preparing to generate the ALSA configuration file Nov 29 15:01:19 volumio volumio[1262]: info: Setting Geolocation for MyVolumio to eu6 Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio systemd[1]: apt-daily.service: Succeeded. Nov 29 15:01:19 volumio systemd[1]: Started Daily apt download activities. Nov 29 15:01:19 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="completed challenge" Nov 29 15:01:19 volumio volumio[1262]: error: Failed to ping endpoint au1.myvolumio.org : unknown error Nov 29 15:01:19 volumio volumio[1262]: info: Setting Geolocation for MyVolumio to eu6 Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio volumio[1262]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 29 15:01:19 volumio volumio[1262]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 15:01:19 volumio volumio[1262]: Error: Unable to resolve or reject the same promise twice Nov 29 15:01:19 volumio volumio[1262]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Nov 29 15:01:19 volumio volumio[1262]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Nov 29 15:01:19 volumio volumio[1262]: at Socket.emit (events.js:412:35) Nov 29 15:01:19 volumio volumio[1262]: at endReadableNT (internal/streams/readable.js:1333:12) Nov 29 15:01:19 volumio volumio[1262]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Nov 29 15:01:19 volumio volumio[1262]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="authenticated as 1166952911" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="authenticated as 1166952911" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="dealer connection opened" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="initializing zeroconf session, username: 1166952911" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="update volume to 15728/65535" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=error msg="failed put state after volume change" error="put state request failed with status 400: Require at least one of callback url or connection id" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=trace msg="emitting websocket event: volume" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="received connection id: NjA0NzdmNzEtNmNlNC00NmI4LWIyYTYtMzc4NmRhYzQ4NThkK2RlYWxlcit0Y3A6Ly8wYWNhNTljMy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRjIxMkZDNEZDOTAxNjcyQUE4QUIwMjIwRTE0QzY4MjI4MjM1NjIxNkIwMkI2MTM5OUVCQjE4QkJCRDgzNUI4NA==" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 29 15:01:19 volumio go-librespot[1895]: time="2024-11-29T15:01:19+01:00" level=debug msg="autoplay enabled: false" Nov 29 15:01:19 volumio sudo[2296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-29 15:00 Nov 29 15:01:19 volumio sudo[2296]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"