-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Fri 2024-11-22 22:59:41 CST. -- Nov 22 22:59:36 telos-emp systemd[1]: Starting Daily apt download activities... Nov 22 22:59:36 telos-emp ntpd[676]: receive: Unexpected origin timestamp 0xe8ec68a8.0d6a972c does not match aorg 0000000000.00000000 from server@125.229.106.76 xmt 0xeaeb1ad8.e414b8a1 Nov 22 22:59:36 telos-emp ntpd[676]: receive: Unexpected origin timestamp 0xe8ec68a8.0d66cace does not match aorg 0000000000.00000000 from server@122.117.253.246 xmt 0xeaeb1ad8.e68de966 Nov 22 22:59:36 telos-emp ntpd[676]: receive: Unexpected origin timestamp 0xe8ec68a8.0d6f18a4 does not match aorg 0000000000.00000000 from server@103.147.22.149 xmt 0xeaeb1ad8.e9a11488 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: A device disappeared from network Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: A device disappeared from network Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: A device disappeared from network Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.159100, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 169.254.255.255(138) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.159589, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.159734, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Nov 22 22:59:37 telos-emp nmbd[653]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.159866, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.159955, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Nov 22 22:59:37 telos-emp nmbd[653]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160033, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160116, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Nov 22 22:59:37 telos-emp nmbd[653]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160226, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160306, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Nov 22 22:59:37 telos-emp nmbd[653]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160385, 0] ../source3/libsmb/nmblib.c:917(send_udp) Nov 22 22:59:37 telos-emp nmbd[653]: Packet send failed to 127.0.0.1(137) ERRNO=Network is unreachable Nov 22 22:59:37 telos-emp nmbd[653]: [2024/11/22 22:59:37.160458, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Nov 22 22:59:37 telos-emp nmbd[653]: send_netbios_packet: send_packet() to IP 127.0.0.1 port 137 failed Nov 22 22:59:37 telos-emp volumio[1000]: info: Initializing connection to go-librespot Websocket Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: adding 38cfc858-51c3-477a-abd9-878bd620fa06 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: Found device Telos EMP Nov 22 22:59:37 telos-emp volumio[1000]: info: CoreCommandRouter::volumioGetState Nov 22 22:59:37 telos-emp volumio[1000]: info: CorePlayQueue::getTrack 0 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: this is already registered, 38cfc858-51c3-477a-abd9-878bd620fa06 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: Found device Telos EMP Nov 22 22:59:37 telos-emp volumio[1000]: info: CoreCommandRouter::volumioGetState Nov 22 22:59:37 telos-emp volumio[1000]: info: CorePlayQueue::getTrack 0 Nov 22 22:59:37 telos-emp volumio[1000]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: this is already registered, 38cfc858-51c3-477a-abd9-878bd620fa06 Nov 22 22:59:37 telos-emp volumio[1000]: info: Discovery: Found device Telos EMP Nov 22 22:59:37 telos-emp volumio[1000]: info: CoreCommandRouter::volumioGetState Nov 22 22:59:37 telos-emp volumio[1000]: info: CorePlayQueue::getTrack 0 Nov 22 22:59:37 telos-emp systemd[1]: apt-daily.service: Succeeded. Nov 22 22:59:37 telos-emp systemd[1]: Started Daily apt download activities. Nov 22 22:59:37 telos-emp systemd[1]: Starting Daily apt upgrade and clean activities... Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin bluetooth to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin multiroom to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin metavolumio to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin cd_controller to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 22 22:59:37 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 22 22:59:38 telos-emp systemd[1]: apt-daily-upgrade.service: Succeeded. Nov 22 22:59:38 telos-emp systemd[1]: Started Daily apt upgrade and clean activities. Nov 22 22:59:38 telos-emp systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 22 22:59:38 telos-emp systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Nov 22 22:59:38 telos-emp systemd[1]: Stopped go-librespot Daemon. Nov 22 22:59:38 telos-emp systemd[1]: Started go-librespot Daemon. Nov 22 22:59:38 telos-emp go-librespot[1592]: Librespot-go daemon starting... Nov 22 22:59:38 telos-emp go-librespot[1592]: time="2024-11-22T22:59:38+08:00" level=info msg="generated new device id: a2db9807de7d095129a473e28b61a6be973d7732" Nov 22 22:59:38 telos-emp go-librespot[1592]: time="2024-11-22T22:59:38+08: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]" Nov 22 22:59:38 telos-emp go-librespot[1592]: time="2024-11-22T22:59:38+08: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]" Nov 22 22:59:38 telos-emp go-librespot[1592]: time="2024-11-22T22:59:38+08: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]" Nov 22 22:59:38 telos-emp go-librespot[1592]: time="2024-11-22T22:59:38+08:00" level=debug msg="zeroconf server listening on port 43911" Nov 22 22:59:38 telos-emp volumio[1000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 22 22:59:38 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 22 22:59:38 telos-emp volumio[1000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 22 22:59:38 telos-emp volumio[1000]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 22 22:59:38 telos-emp volumio[1000]: info: Starting MyVolumio Remote Streaming Endpoints Nov 22 22:59:38 telos-emp volumio[1000]: info: MyVolumio login type: Token Nov 22 22:59:38 telos-emp volumio[1000]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 22 22:59:38 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 22 22:59:39 telos-emp volumio[1000]: info: Starting Streaming Service Transparent Proxy Nov 22 22:59:39 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 22 22:59:39 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 22 22:59:39 telos-emp volumio[1000]: info: Streaming services startup Nov 22 22:59:39 telos-emp volumio[1000]: info: Starting Streaming Daemon Nov 22 22:59:39 telos-emp sudo[1607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 22 22:59:39 telos-emp sudo[1607]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 22 22:59:39 telos-emp sudo[1607]: pam_unix(sudo:session): session closed for user root Nov 22 22:59:39 telos-emp volumio[1000]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 22 22:59:39 telos-emp volumio[1000]: error: Cannot start Volumio Streaming Daemon Nov 22 22:59:39 telos-emp volumio[1000]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 22 22:59:39 telos-emp volumio[1000]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 22 22:59:39 telos-emp go-librespot[1592]: time="2024-11-22T22:59:39+08:00" level=debug msg="obtained new client token: AADlscDfb3fB5bsLysOm8gmEEzREEWW4dXKKd4uNn3YoSFMr1pTH8o+EZyktCD3Y0igpMLx/U2JbahSFb5VgBIDiQovnQ7WNDnM+UZtz9tq/YaWgjJWkiSD7PJRBjlhuUkgsvHXCp/XSh+LLA3KKTISmfzrBM5uXYwBRbRmyd9PrJy38Mr/m5U4KJBrDpsAOo/YZMD1i19qlMpr2cKlSUxvrgxi6nh6hQGdndSjkeKlkT0Nio0+7COyg68X+I1JR" Nov 22 22:59:39 telos-emp go-librespot[1592]: time="2024-11-22T22:59:39+08:00" level=debug msg="completed keyexchange" Nov 22 22:59:40 telos-emp volumio[1000]: error: MyVolumio Custom Token format not valid, refreshing it Nov 22 22:59:40 telos-emp volumio[1000]: info: Initializing connection to go-librespot Websocket Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="new websocket client" Nov 22 22:59:40 telos-emp volumio[1000]: info: Connection to go-librespot Websocket established Nov 22 22:59:40 telos-emp volumio[1000]: STREAMING PROXY: Starting server on port 3245 Nov 22 22:59:40 telos-emp volumio[1000]: Node JS runtime: 14 Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="completed challenge" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="authenticated as 31hjhhtxr2tgcm57d5rck6ud3u6e" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="authenticated as 31hjhhtxr2tgcm57d5rck6ud3u6e" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="dealer connection opened" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=info msg="accepted zeroconf user 31hjhhtxr2tgcm57d5rck6ud3u6e from XQ-BC72" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="received connection id: MDFjYzVmYWUtNzRjYS00NzlmLTlmOWItYjI2MzA1ZTEwZjEwK2RlYWxlcit0Y3A6Ly8wYWM5NDkxMy5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArRDk2MjVBMUFFMDc2RTJEQ0JDQTEzMDkyMDlCNEI0MkNFNEEwMEU0NDZCRTc2NjZEQjAyNEMyNkQzMTQ4RUI2Rg==" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="put connect state because NEW_DEVICE" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="handling transfer player command from d7cf053a01b3c1ec11641ac3607b3c62b64beb69" Nov 22 22:59:40 telos-emp go-librespot[1592]: time="2024-11-22T22:59:40+08:00" level=debug msg="loading track spotify:track:0f4YTikmB09RKwNEjzG17Y (paused: true, position: 51626ms)" Nov 22 22:59:40 telos-emp volumio[1000]: info: MyVolumio login type: Token Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=trace msg="emitting websocket event: will_play" Nov 22 22:59:41 telos-emp volumio[1000]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0f4YTikmB09RKwNEjzG17Y","play_origin":"google-clock"}} Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0f4YTikmB09RKwNEjzG17Y" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="requested aes key for file 1d56054d923362d6ea06f34606310bd700687d31, gid: 0f4YTikmB09RKwNEjzG17Y" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1366" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched first chunk of 11, total size is 5576292 bytes" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 2/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 1/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 3/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=trace msg="seek to 51626ms (diff: 80ms, samples: 2276706, bytes: 1828705)" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 4/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 5/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=info msg="loaded track \"Romeo and Juliette, Op. 64 (Arr. for Viola and Piano by Vadim Borisovsky, Orchestration for Viola and String Orchestra by François Vallières): Introduction\" (uri: spotify:track:0f4YTikmB09RKwNEjzG17Y, paused: true, position: 51626ms, duration: 155840ms)" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="fetched chunk 6/10, size: 524288" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1128" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=trace msg="emitting websocket event: metadata" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=trace msg="emitting websocket event: active" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="sending successful reply for delaer request" Nov 22 22:59:41 telos-emp volumio[1000]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0f4YTikmB09RKwNEjzG17Y","name":"Romeo and Juliette, Op. 64 (Arr. for Viola and Piano by Vadim Borisovsky, Orchestration for Viola and String Orchestra by François Vallières): Introduction","artist_names":["Sergei Prokofiev","Elvira Misbakhova","I Musici de Montréal","Jean-François Rivest"],"album_name":"Destins tragiques","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02876ea0762ef454945bf4d520","position":51626,"duration":155840}} Nov 22 22:59:41 telos-emp volumio[1000]: SPOTIFY: received: {"type":"active","data":null} Nov 22 22:59:41 telos-emp volumio[1000]: info: Aligning Spotify Volume to Volumio Volume Nov 22 22:59:41 telos-emp volumio[1000]: info: CoreCommandRouter::volumioGetState Nov 22 22:59:41 telos-emp volumio[1000]: info: CorePlayQueue::getTrack 0 Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 22 22:59:41 telos-emp go-librespot[1592]: time="2024-11-22T22:59:41+08:00" level=trace msg="emitting websocket event: paused" Nov 22 22:59:41 telos-emp volumio[1000]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0f4YTikmB09RKwNEjzG17Y","play_origin":"google-clock"}} Nov 22 22:59:41 telos-emp volumio[1000]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 22:59:41 telos-emp volumio[1000]: TypeError: Cannot read property 'service' of undefined Nov 22 22:59:41 telos-emp volumio[1000]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:322:50) Nov 22 22:59:41 telos-emp volumio[1000]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:256:18) Nov 22 22:59:41 telos-emp volumio[1000]: at WebSocket.message (/data/plugins/music_service/spop/index.js:175:14) Nov 22 22:59:41 telos-emp volumio[1000]: at WebSocket.emit (events.js:315:20) Nov 22 22:59:41 telos-emp volumio[1000]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1192:20) Nov 22 22:59:41 telos-emp volumio[1000]: at Receiver.emit (events.js:315:20) Nov 22 22:59:41 telos-emp volumio[1000]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:560:14) Nov 22 22:59:41 telos-emp volumio[1000]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:478:17) Nov 22 22:59:41 telos-emp volumio[1000]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:22) Nov 22 22:59:41 telos-emp volumio[1000]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:180:18 Nov 22 22:59:41 telos-emp volumio[1000]: at internal/process/task_queues.js:149:7 Nov 22 22:59:41 telos-emp volumio[1000]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Nov 22 22:59:41 telos-emp volumio[1000]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Nov 22 22:59:41 telos-emp volumio[1000]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Nov 22 22:59:41 telos-emp volumio[1000]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 22 22:59:41 telos-emp sudo[1625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-22 22:58 Nov 22 22:59:41 telos-emp sudo[1625]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"