-- Logs begin at Fri 2025-08-29 16:43:45 MSK, end at Fri 2025-08-29 16:45:51 MSK. -- Aug 29 16:44:00 volumio volumio[1117]: verbose: New Socket.io Connection to 192.168.1.123 from 192.168.1.60 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 YaBrowser/25.8.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetVisibleSources Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 29 16:44:00 volumio volumio[1117]: info: Received Get System Info Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:44:00 volumio volumio[1117]: info: Discovery: Getting this device information Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:00 volumio volumio[1117]: info: Listing playlists Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:44:00 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 16:44:00 volumio volumio[1117]: info: Received Get System Info Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:44:00 volumio volumio[1117]: info: Discovery: Getting this device information Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:00 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:00 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:44:00 volumio volumio[1117]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 29 16:44:01 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Aug 29 16:44:02 volumio volumio-time-update[798]: volumio-time-update-util: Fetching time from Volumio... Aug 29 16:44:02 volumio volumio-time-update[798]: volumio-time-update-util: Setting system time to: 2025-08-29 16:44:02 Aug 29 16:44:02 volumio sudo[1944]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-08-29 16:44:02 Aug 29 16:44:02 volumio sudo[1944]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:02 volumio dbus-daemon[807]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.16' (uid=0 pid=1945 comm="timedatectl set-time 2025-08-29 16:44:02 ") Aug 29 16:44:02 volumio systemd[1]: Starting Time & Date Service... Aug 29 16:44:02 volumio dbus-daemon[807]: [system] Successfully activated service 'org.freedesktop.timedate1' Aug 29 16:44:02 volumio systemd[1]: Started Time & Date Service. Aug 29 16:44:02 volumio systemd-timedated[1946]: Changed local time to Fri Aug 29 16:44:02 2025 Aug 29 16:44:02 volumio sudo[1944]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:02 volumio volumio-time-update[798]: volumio-time-update-util: System time updated successfully. Aug 29 16:44:02 volumio systemd[1]: Started Volumio Time Update Utility. Aug 29 16:44:03 volumio volumio[1117]: info: Volumio Network Manager: Network status updated: 1 Aug 29 16:44:03 volumio sudo[1963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 29 16:44:03 volumio sudo[1963]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:03 volumio sudo[1963]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:03 volumio sudo[1966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 29 16:44:03 volumio sudo[1966]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:03 volumio sudo[1966]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:03 volumio sudo[1969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 29 16:44:03 volumio sudo[1969]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:03 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Aug 29 16:44:03 volumio sudo[1969]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:03 volumio volumio[1117]: info: Upmpdcli Daemon Started Aug 29 16:44:03 volumio volumio[1971]: Generating RSA private key, 4096 bit long modulus (2 primes) Aug 29 16:44:03 volumio volumio[1971]: ....++++ Aug 29 16:44:03 volumio volumio[1971]: ...++++ Aug 29 16:44:03 volumio volumio[1971]: e is 65537 (0x010001) Aug 29 16:44:03 volumio volumio[1971]: writing RSA key Aug 29 16:44:04 volumio ntpd[1766]: Soliciting pool server 193.192.36.3 Aug 29 16:44:04 volumio ntpd[1766]: Soliciting pool server 217.69.139.133 Aug 29 16:44:04 volumio ntpd[1766]: Soliciting pool server 162.159.200.1 Aug 29 16:44:04 volumio ntpd[1766]: Soliciting pool server 213.234.203.30 Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin bluetooth to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin multiroom to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin metavolumio to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin cd_controller to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 29 16:44:04 volumio volumio[1117]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 29 16:44:05 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:05 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:05 volumio volumio[1117]: info: Starting MyVolumio Remote Streaming Endpoints Aug 29 16:44:05 volumio volumio[1117]: info: MyVolumio login type: Token Aug 29 16:44:05 volumio ntpd[1766]: Soliciting pool server 91.201.254.110 Aug 29 16:44:05 volumio ntpd[1766]: Soliciting pool server 92.255.126.17 Aug 29 16:44:05 volumio ntpd[1766]: Soliciting pool server 91.206.16.3 Aug 29 16:44:05 volumio ntpd[1766]: Soliciting pool server 195.39.248.3 Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 29 16:44:05 volumio volumio[1117]: info: Starting Streaming Service Transparent Proxy Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 29 16:44:05 volumio volumio[1117]: info: Streaming services startup Aug 29 16:44:05 volumio volumio[1117]: info: Starting Streaming Daemon Aug 29 16:44:05 volumio sudo[2009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 16:44:05 volumio sudo[2009]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:05 volumio sudo[2009]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:05 volumio volumio[1117]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 29 16:44:05 volumio volumio[1117]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=3.832&uuid=1f2c0b84b490e56f304bfab5d58314b5" http://updates.volumio.org/downloader-v1/track-device Aug 29 16:44:05 volumio volumio[1117]: % Total % Received % Xferd Average Speed Time Time Time Current Aug 29 16:44:05 volumio volumio[1117]: Dload Upload Total Spent Left Speed Aug 29 16:44:05 volumio volumio[1117]: [132B blob data] Aug 29 16:44:05 volumio volumio[1117]: retrying in 5 seconds, trial 0 Aug 29 16:44:05 volumio volumio[1117]: info: Volumio Calling Home Aug 29 16:44:05 volumio volumio[1117]: error: Cannot start Volumio Streaming Daemon Aug 29 16:44:05 volumio volumio[1117]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 16:44:05 volumio volumio[1117]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 16:44:05 volumio volumio[1117]: STREAMING PROXY: Starting server on port 3245 Aug 29 16:44:05 volumio volumio[1117]: Node JS runtime: 14 Aug 29 16:44:06 volumio volumio[1117]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 29 16:44:06 volumio ntpd[1766]: Soliciting pool server 92.255.126.3 Aug 29 16:44:06 volumio ntpd[1766]: Soliciting pool server 51.250.68.198 Aug 29 16:44:06 volumio ntpd[1766]: Soliciting pool server 178.186.127.28 Aug 29 16:44:06 volumio ntpd[1766]: Soliciting pool server 51.250.110.169 Aug 29 16:44:06 volumio volumio[1117]: info: MyVolumio token set successfully Aug 29 16:44:06 volumio volumio[1117]: info: MYVOLUMIO: Adding device Aug 29 16:44:06 volumio volumio[1117]: info: MYVOLUMIO: Evaluating Server Aug 29 16:44:06 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 29 16:44:07 volumio ntpd[1766]: Soliciting pool server 92.255.126.1 Aug 29 16:44:07 volumio ntpd[1766]: Soliciting pool server 78.36.199.163 Aug 29 16:44:07 volumio ntpd[1766]: Soliciting pool server 82.142.168.18 Aug 29 16:44:07 volumio ntpd[1766]: Soliciting pool server 188.134.76.192 Aug 29 16:44:08 volumio ntpd[1766]: Soliciting pool server 2a01:9f60:5:722b:1337:c0de:4:11 Aug 29 16:44:08 volumio ntpd[1766]: Soliciting pool server 192.36.143.130 Aug 29 16:44:10 volumio volumio[1117]: info: Volumio called home Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.2683e039 does not match aorg 0000000000.00000000 from server@51.250.68.198 xmt 0xec5c2d2b.8250bf56 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.2686c110 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xec5c2d2b.82d56d56 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.26862d4e does not match aorg 0000000000.00000000 from server@92.255.126.17 xmt 0xec5c2d2b.82f31ef0 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.26834b3e does not match aorg 0000000000.00000000 from server@51.250.110.169 xmt 0xec5c2d2b.836d068a Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.2682a7fc does not match aorg 0000000000.00000000 from server@92.255.126.3 xmt 0xec5c2d2b.84c5f822 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.2685998a does not match aorg 0000000000.00000000 from server@91.201.254.110 xmt 0xec5c2d2b.8347a64a Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.26820a73 does not match aorg 0000000000.00000000 from server@188.134.76.192 xmt 0xec5c2d2b.849406f6 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.26850576 does not match aorg 0000000000.00000000 from server@195.39.248.3 xmt 0xec5c2d2b.84de5fad Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.2687e21f does not match aorg 0000000000.00000000 from server@193.192.36.3 xmt 0xec5c2d2b.9dbf3608 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.268135d5 does not match aorg 0000000000.00000000 from server@78.36.199.163 xmt 0xec5c2d2b.865c4016 Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.26847334 does not match aorg 0000000000.00000000 from server@91.206.16.3 xmt 0xec5c2d2b.861afd0e Aug 29 16:44:11 volumio volumio[1117]: info: MyVolumio status changed Aug 29 16:44:11 volumio volumio[1117]: info: Streaming services startup Aug 29 16:44:11 volumio volumio[1117]: info: Starting Streaming Daemon Aug 29 16:44:11 volumio volumio[1117]: info: Removing browser output: myVolumio user plan is not superstar Aug 29 16:44:11 volumio volumio[1117]: info: Removing audio output: Aug 29 16:44:11 volumio volumio[1117]: info: Stoppping Tunnel 1 Aug 29 16:44:11 volumio sudo[2040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 29 16:44:11 volumio sudo[2040]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:11 volumio ntpd[1766]: receive: Unexpected origin timestamp 0xec5c2d2b.267e2bc2 does not match aorg 0000000000.00000000 from server@192.36.143.130 xmt 0xec5c2d2b.8be2ddac Aug 29 16:44:11 volumio sudo[2040]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:11 volumio volumio[1117]: error: Cannot start Volumio Streaming Daemon Aug 29 16:44:11 volumio volumio[1117]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 29 16:44:11 volumio volumio[1117]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 29 16:44:11 volumio sudo[2043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 29 16:44:11 volumio sudo[2043]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:11 volumio sudo[2043]: pam_unix(sudo:session): session closed for user root Aug 29 16:44:11 volumio volumio[1117]: info: Remote SSH Stopped Aug 29 16:44:11 volumio volumio[1117]: info: Setting Geolocation for MyVolumio to eu10 Aug 29 16:44:11 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:11 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:11 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:12 volumio volumio[1117]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 29 16:44:12 volumio volumio[1117]: info: Updating MyVolumio device info Aug 29 16:44:12 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:12 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:12 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:13 volumio volumio[1117]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 16:44:15 volumio volumio[1117]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 29 16:44:15 volumio volumio[1117]: info: Received Get System Version Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:44:15 volumio volumio[1117]: info: Received Get System Info Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 29 16:44:15 volumio volumio[1117]: info: Discovery: Getting this device information Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:15 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 29 16:44:16 volumio volumio[1117]: info: MYVOLUMIO: Adding device Aug 29 16:44:16 volumio volumio[1117]: info: MYVOLUMIO: Evaluating Server Aug 29 16:44:16 volumio systemd[1]: systemd-fsckd.service: Succeeded. Aug 29 16:44:16 volumio volumio[1117]: info: Setting Geolocation for MyVolumio to eu5 Aug 29 16:44:16 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:16 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:16 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:17 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Aug 29 16:44:17 volumio volumio[1117]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Aug 29 16:44:17 volumio volumio[1117]: info: Updating MyVolumio device info Aug 29 16:44:17 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:17 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:17 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:18 volumio volumio[1117]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Aug 29 16:44:20 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 29 16:44:20 volumio volumio[1117]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Aug 29 16:44:20 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:20 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::volumioGetBrowseSources Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 29 16:44:25 volumio volumio-remote-updater[796]: No test mode Aug 29 16:44:25 volumio volumio-remote-updater[796]: No alpha test mode Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 29 16:44:25 volumio volumio[1117]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 29 16:44:25 volumio volumio[1117]: info: Completed starting MyVolumio Plugin Aug 29 16:44:25 volumio volumio[1117]: [Metrics] CommandRouter: 33s 713.98ms Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::volumiosetStartupVolume Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::Close All Modals sent Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::Close All Modals sent Aug 29 16:44:25 volumio volumio[1117]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 29 16:44:25 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 29 16:44:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 29 16:44:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 29 16:44:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 29 16:44:32 volumio systemd[1]: systemd-timedated.service: Succeeded. Aug 29 16:44:32 volumio volumio[1117]: info: BOOT COMPLETED Aug 29 16:44:46 volumio systemd[1]: Started My Shell Script. Aug 29 16:44:46 volumio systemd[1]: Reached target Multi-User System. Aug 29 16:44:46 volumio systemd[1]: Reached target Graphical Interface. Aug 29 16:44:46 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 29 16:44:46 volumio sudo[2130]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/bash /home/volumio/scripts/peppy.sh Aug 29 16:44:46 volumio sudo[2130]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:44:46 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Aug 29 16:44:46 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 29 16:44:46 volumio systemd[1]: Startup finished in 6.484s (firmware) + 1.980s (loader) + 6.133s (kernel) + 1min 1.566s (userspace) = 1min 16.164s. Aug 29 16:44:56 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:44:56 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:01 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:01 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:06 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:06 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:11 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:11 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:14 volumio volumio[1117]: info: CoreCommandRouter::volumioPlay Aug 29 16:45:14 volumio volumio[1117]: info: CoreStateMachine::play index undefined Aug 29 16:45:14 volumio volumio[1117]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 16:45:14 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:14 volumio volumio[1117]: info: CoreStateMachine::startPlaybackTimer Aug 29 16:45:14 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:14 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 16:45:14 volumio volumio[1117]: info: sendMpdCommand stop took 0 milliseconds Aug 29 16:45:14 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 16:45:14 volumio volumio[1117]: info: Aug 29 16:45:14 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:14 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:14 volumio volumio[1117]: info: sendMpdCommand clear took 1 milliseconds Aug 29 16:45:14 volumio volumio[1117]: error: updateQueue error: null Aug 29 16:45:14 volumio volumio[1117]: info: ------------------------------ 5ms Aug 29 16:45:14 volumio volumio[1117]: error: Upnp client error: Error: This socket has been ended by the other party Aug 29 16:45:14 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Df7f0b6941aca3471ec88181d1976c645e7e50b184bb5e404c65ba2201d119e45%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68befc3d%2F0%2F107535%2F9aca77c4.206171208.6.141251209%2F320.mp3&ext=.mp3" Aug 29 16:45:14 volumio volumio[1117]: info: Aug 29 16:45:14 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:14 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:14 volumio volumio[1117]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Df7f0b6941aca3471ec88181d1976c645e7e50b184bb5e404c65ba2201d119e45%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68befc3d%2F0%2F107535%2F9aca77c4.206171208.6.141251209%2F320.mp3&ext=.mp3" took 1 milliseconds Aug 29 16:45:14 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:14 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:14 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:14 volumio volumio[1117]: info: Aug 29 16:45:14 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:14 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:14 volumio volumio[1117]: info: ------------------------------ 2ms Aug 29 16:45:14 volumio volumio[1117]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 16:45:14 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand play Aug 29 16:45:14 volumio volumio[1117]: info: ------------------------------ 1ms Aug 29 16:45:14 volumio volumio[1117]: info: sendMpdCommand play took 0 milliseconds Aug 29 16:45:15 volumio volumio[1117]: info: Aug 29 16:45:15 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:15 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:15 volumio volumio[1117]: info: sendMpdCommand status took 30 milliseconds Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 16:45:15 volumio volumio[1117]: info: Aug 29 16:45:15 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:15 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:15 volumio volumio[1117]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::parseTrackInfo Aug 29 16:45:15 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:15 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:15 volumio volumio[1117]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":156,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"SARAVIA FUNK - Mega Slowed Instrumental","artist":"RD12","album":"SARAVIA FUNK","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Df7f0b6941aca3471ec88181d1976c645e7e50b184bb5e404c65ba2201d119e45%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68befc3d%2F0%2F107535%2F9aca77c4.206171208.6.141251209%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 29 16:45:15 volumio volumio[1117]: verbose: CURRENT POSITION 0 Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::syncState stateService play Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus stop Aug 29 16:45:15 volumio volumio[1117]: info: ------------------------------ 35ms Aug 29 16:45:15 volumio volumio[1117]: info: sendMpdCommand status took 3 milliseconds Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 16:45:15 volumio volumio[1117]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 29 16:45:15 volumio volumio[1117]: verbose: ControllerMpd::parseTrackInfo Aug 29 16:45:15 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:15 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:15 volumio volumio[1117]: verbose: STATE SERVICE {"status":"play","position":0,"seek":728,"duration":156,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"SARAVIA FUNK - Mega Slowed Instrumental","artist":"RD12","album":"SARAVIA FUNK","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3Df7f0b6941aca3471ec88181d1976c645e7e50b184bb5e404c65ba2201d119e45%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68befc3d%2F0%2F107535%2F9aca77c4.206171208.6.141251209%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 29 16:45:15 volumio volumio[1117]: verbose: CURRENT POSITION 0 Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::syncState stateService play Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus play Aug 29 16:45:15 volumio volumio[1117]: info: Received an update from plugin. extracting info from payload Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:15 volumio volumio[1117]: info: ------------------------------ 12ms Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:45:15 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:45:15 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:45:15 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:45:15 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:45:16 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:16 volumio sudo[2273]: root : TTY=unknown ; PWD=/data/plugins/user_interface/peppy_screensaver ; USER=root ; COMMAND=/bin/bash run_peppymeter.sh Aug 29 16:45:16 volumio sudo[2273]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 16:45:17 volumio volumio[1117]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 8 Aug 29 16:45:17 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:18 volumio volumio[1117]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 9 Aug 29 16:45:18 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioNext Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::next Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::next Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand next Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand next took 3 milliseconds Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand status took 1 milliseconds Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 0 Aug 29 16:45:26 volumio volumio[1117]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 29 16:45:26 volumio volumio[1117]: verbose: CURRENT POSITION 0 Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState stateService stop Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus play Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::play index undefined Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::startPlaybackTimer Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand stop Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 15ms Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand stop took 13 milliseconds Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand clear Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:26 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand clear took 7 milliseconds Aug 29 16:45:26 volumio volumio[1117]: error: updateQueue error: null Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 11ms Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D260a81547fa7ab744c6b3957e1745d717994011513750892df667e6cad1ceb46%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68bf9ad7%2F0%2F13534011%2Fcc928a87.190605255.7.129291391%2F320.mp3&ext=.mp3" Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:26 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D260a81547fa7ab744c6b3957e1745d717994011513750892df667e6cad1ceb46%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68bf9ad7%2F0%2F13534011%2Fcc928a87.190605255.7.129291391%2F320.mp3&ext=.mp3" took 0 milliseconds Aug 29 16:45:26 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:26 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:26 volumio volumio[1117]: verbose: MPD COMMAND [object Object] Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces system playlist update Aug 29 16:45:26 volumio volumio[1117]: info: Ignoring MPD Status Update Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 1ms Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand play Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 2ms Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand play took 1 milliseconds Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:26 volumio volumio[1117]: info: Aug 29 16:45:26 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand status took 3 milliseconds Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand status took 1 milliseconds Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::parseTrackInfo Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":128,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Гроза","artist":"BEARWOLF","album":"Гроза","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D260a81547fa7ab744c6b3957e1745d717994011513750892df667e6cad1ceb46%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68bf9ad7%2F0%2F13534011%2Fcc928a87.190605255.7.129291391%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 29 16:45:26 volumio volumio[1117]: verbose: CURRENT POSITION 1 Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState stateService play Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus stop Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 5ms Aug 29 16:45:26 volumio volumio[1117]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 29 16:45:26 volumio volumio[1117]: verbose: ControllerMpd::parseTrackInfo Aug 29 16:45:26 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:26 volumio volumio[1117]: verbose: STATE SERVICE {"status":"play","position":0,"seek":754,"duration":128,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Гроза","artist":"BEARWOLF","album":"Гроза","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D260a81547fa7ab744c6b3957e1745d717994011513750892df667e6cad1ceb46%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68bf9ad7%2F0%2F13534011%2Fcc928a87.190605255.7.129291391%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 29 16:45:26 volumio volumio[1117]: verbose: CURRENT POSITION 1 Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState stateService play Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus play Aug 29 16:45:26 volumio volumio[1117]: info: Received an update from plugin. extracting info from payload Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:26 volumio volumio[1117]: info: ------------------------------ 11ms Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:45:26 volumio volumio[1117]: info: CoreCommandRouter::volumioGetQueue Aug 29 16:45:26 volumio volumio[1117]: info: CoreStateMachine::getQueue Aug 29 16:45:26 volumio volumio[1117]: info: CorePlayQueue::getQueue Aug 29 16:45:28 volumio volumio[1117]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 9 Aug 29 16:45:28 volumio volumio[1117]: info: CoreCommandRouter::volumioGetState Aug 29 16:45:51 volumio volumio[1117]: info: CoreCommandRouter::volumioPause Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::pause Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::stPlaybackTimer Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::servicePause Aug 29 16:45:51 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:51 volumio volumio[1117]: info: CoreCommandRouter::servicePause Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 29 16:45:51 volumio volumio[1117]: info: ControllerMpd::pause Aug 29 16:45:51 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand pause Aug 29 16:45:51 volumio volumio[1117]: info: Aug 29 16:45:51 volumio volumio[1117]: ---------------------------- MPD announces state update: player Aug 29 16:45:51 volumio volumio[1117]: info: sendMpdCommand pause took 1 milliseconds Aug 29 16:45:51 volumio volumio[1117]: info: ControllerMpd::getState Aug 29 16:45:51 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand status Aug 29 16:45:51 volumio volumio[1117]: info: sendMpdCommand status took 0 milliseconds Aug 29 16:45:51 volumio volumio[1117]: verbose: ControllerMpd::parseState Aug 29 16:45:51 volumio volumio[1117]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 29 16:45:51 volumio volumio[1117]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 29 16:45:51 volumio volumio[1117]: verbose: ControllerMpd::parseTrackInfo Aug 29 16:45:51 volumio volumio[1117]: info: ControllerMpd::pushState Aug 29 16:45:51 volumio volumio[1117]: info: CoreCommandRouter::servicePushState Aug 29 16:45:51 volumio volumio[1117]: info: CorePlayQueue::getTrack 1 Aug 29 16:45:51 volumio volumio[1117]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":25456,"duration":128,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Гроза","artist":"BEARWOLF","album":"Гроза","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fext-strm-rndttk-01.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D260a81547fa7ab744c6b3957e1745d717994011513750892df667e6cad1ceb46%2Clid%3D1595%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D68bf9ad7%2F0%2F13534011%2Fcc928a87.190605255.7.129291391%2F320.mp3&ext=.mp3","trackType":"mp3"} Aug 29 16:45:51 volumio volumio[1117]: verbose: CURRENT POSITION 1 Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::syncState stateService pause Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::syncState currentStatus pause Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::pushState Aug 29 16:45:51 volumio volumio[1117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 16:45:51 volumio volumio[1117]: info: CoreCommandRouter::volumioPushState Aug 29 16:45:51 volumio volumio[1117]: info: CoreStateMachine::stPlaybackTimer Aug 29 16:45:51 volumio volumio[1117]: info: ------------------------------ 9ms Aug 29 16:45:51 volumio volumio[1117]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 16:45:51 volumio volumio[1117]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Aug 29 16:45:51 volumio volumio[1117]: at Object.readdirSync (fs.js:1048:3) Aug 29 16:45:51 volumio volumio[1117]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Aug 29 16:45:51 volumio volumio[1117]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Aug 29 16:45:51 volumio volumio[1117]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Aug 29 16:45:51 volumio volumio[1117]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Aug 29 16:45:51 volumio volumio[1117]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Aug 29 16:45:51 volumio volumio[1117]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 29 16:45:51 volumio volumio[1117]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Aug 29 16:45:51 volumio volumio[1117]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Aug 29 16:45:51 volumio volumio[1117]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 29 16:45:51 volumio volumio[1117]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 29 16:45:51 volumio volumio[1117]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Aug 29 16:45:51 volumio volumio[1117]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Aug 29 16:45:51 volumio volumio[1117]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Aug 29 16:45:51 volumio volumio[1117]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Aug 29 16:45:51 volumio volumio[1117]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Aug 29 16:45:51 volumio volumio[1117]: errno: -20, Aug 29 16:45:51 volumio volumio[1117]: syscall: 'scandir', Aug 29 16:45:51 volumio volumio[1117]: code: 'ENOTDIR', Aug 29 16:45:51 volumio volumio[1117]: path: '/tmp/peppyrunning' Aug 29 16:45:51 volumio volumio[1117]: } Aug 29 16:45:51 volumio volumio[1117]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 16:45:51 volumio sudo[2526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-29 16:44 Aug 29 16:45:51 volumio sudo[2526]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:08:46 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="9ef0bfa9b61509be20c9051562554f31"