-- Logs begin at Thu 2019-02-14 11:11:59 WAT, end at Fri 2024-09-06 21:13:21 WAT. -- Sep 06 21:12:00 volumio volumio[899]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 21:12:07 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:07 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:07 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:07 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:07 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:09 volumio volumio[899]: info: Received OAUTH Data Sep 06 21:12:09 volumio volumio[899]: info: Executing Spotify Oauth Login Sep 06 21:12:09 volumio volumio[899]: info: Saving Spotify Refresh Token Sep 06 21:12:11 volumio sudo[8974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 06 21:12:11 volumio sudo[8974]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 21:12:11 volumio sudo[8974]: pam_unix(sudo:session): session closed for user root Sep 06 21:12:11 volumio sudo[8976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 06 21:12:11 volumio sudo[8976]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 21:12:11 volumio sudo[8976]: pam_unix(sudo:session): session closed for user root Sep 06 21:12:11 volumio volumio[899]: verbose: New Socket.io Connection to 192.168.1.15 from 192.168.1.254 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/128.0.0.0 Safari/537.36 Edg/128.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::volumioGetVisibleSources Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:11 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 06 21:12:11 volumio volumio[899]: info: Received Get System Info Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 21:12:11 volumio volumio[899]: info: Discovery: Getting this device information Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:11 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:11 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:11 volumio volumio[899]: info: Listing playlists Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 21:12:11 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 21:12:13 volumio volumio[899]: info: Received Get System Info Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 21:12:13 volumio volumio[899]: info: Discovery: Getting this device information Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:13 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 21:12:13 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 21:12:13 volumio volumio[899]: error: error Sep 06 21:12:13 volumio volumio[899]: error: error Sep 06 21:12:17 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:17 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:17 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:17 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:17 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 21:12:21 volumio volumio[899]: info: Received Get System Info Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 21:12:21 volumio volumio[899]: info: Discovery: Getting this device information Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:21 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 21:12:21 volumio volumio[899]: info: Received Get System Info Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 21:12:21 volumio volumio[899]: info: Discovery: Getting this device information Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:21 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:21 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 21:12:24 volumio volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 21:12:24 volumio volumio[899]: SPOTIFY: BQDxQkt6UUCod07flZSzmtYbtzf7hvVsOtDQ04LY7TBfdNMkBLmM0dckyf0KELTN3eDFDqm5s1cipvOst8l5zLWQ4MUe2QPF8yFXO_VM8QjKVVeRI_m6h4skaveKfw17bvq-PhIacDH43OkdVTU-xTqA71eF726FApzjhXaTqi9zeD1JtfkTnU6ovsOp-tQrEaT5csPOz2j8JK-_RyjYyzXLAE9MXi4CB0Pojn1FJ9aT9OZnAbZK6tw9Fmg Sep 06 21:12:24 volumio volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 21:12:24 volumio volumio[899]: info: New Spotify access token = BQDxQkt6UUCod07flZSzmtYbtzf7hvVsOtDQ04LY7TBfdNMkBLmM0dckyf0KELTN3eDFDqm5s1cipvOst8l5zLWQ4MUe2QPF8yFXO_VM8QjKVVeRI_m6h4skaveKfw17bvq-PhIacDH43OkdVTU-xTqA71eF726FApzjhXaTqi9zeD1JtfkTnU6ovsOp-tQrEaT5csPOz2j8JK-_RyjYyzXLAE9MXi4CB0Pojn1FJ9aT9OZnAbZK6tw9Fmg Sep 06 21:12:24 volumio volumio[899]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 06 21:12:25 volumio volumio[899]: SPOTIFY: User informations: {"display_name":"Collins Olua","external_urls":{"spotify":"https://open.spotify.com/user/collinskcs"},"href":"https://api.spotify.com/v1/users/collinskcs","id":"collinskcs","images":[{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152761601622892&height=50&width=50&ext=1728204727&hash=AbauM6VeSzfv-JkOxshjl49X","height":64,"width":64},{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152761601622892&height=300&width=300&ext=1728204727&hash=AbadYOLkQHp3XVrvDn6kQo6t","height":300,"width":300}],"type":"user","uri":"spotify:user:collinskcs","followers":{"href":null,"total":4},"country":"NG","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"collinskcs@gmail.com"} Sep 06 21:12:25 volumio volumio[899]: info: Creating Spotify config file Sep 06 21:12:25 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 21:12:25 volumio volumio[899]: info: Spotify config file written Sep 06 21:12:25 volumio sudo[9010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Sep 06 21:12:25 volumio sudo[9010]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 21:12:25 volumio systemd[1]: Stopping go-librespot Daemon... Sep 06 21:12:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Sep 06 21:12:25 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Sep 06 21:12:25 volumio systemd[1]: Stopped go-librespot Daemon. Sep 06 21:12:25 volumio volumio[899]: info: Connection to go-librespot Websocket closed Sep 06 21:12:25 volumio systemd[1]: Started go-librespot Daemon. Sep 06 21:12:25 volumio sudo[9010]: pam_unix(sudo:session): session closed for user root Sep 06 21:12:25 volumio go-librespot[9014]: Librespot-go daemon starting... Sep 06 21:12:25 volumio go-librespot[9014]: time="2024-09-06T21:12:25+01:00" level=info msg="generated new device id: da5c244715787c733a4ff78853b29c19d1d579a2" Sep 06 21:12:25 volumio go-librespot[9014]: time="2024-09-06T21:12:25+01:00" level=debug msg="stored credentials not found" Sep 06 21:12:25 volumio volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 21:12:25 volumio volumio[899]: SPOTIFY: BQAf3nvJFKxBfdbMNFkgpMsFsjCXS6mTw2gBHyhfsnkChASEWmC7nrWZDQrHLphJuC4sXA5xlKcT4RxrvjPF9AR4M1RVrNhrdkeKHqZWqM2CcOrKLQRhKyL3jB5Tje6uZ9fRn5XA9Ywcliwz5PvgoQVhytDqVeT2J87CTj5jony7hKy9HMAP3SDA2wxBK39F_UPJWJfCinh8LiCqTST774vP2fxDSKG1G0NM_iTJyVvHtS_6Lj6bIOt8KwQ Sep 06 21:12:25 volumio volumio[899]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Sep 06 21:12:25 volumio volumio[899]: info: New Spotify access token = BQAf3nvJFKxBfdbMNFkgpMsFsjCXS6mTw2gBHyhfsnkChASEWmC7nrWZDQrHLphJuC4sXA5xlKcT4RxrvjPF9AR4M1RVrNhrdkeKHqZWqM2CcOrKLQRhKyL3jB5Tje6uZ9fRn5XA9Ywcliwz5PvgoQVhytDqVeT2J87CTj5jony7hKy9HMAP3SDA2wxBK39F_UPJWJfCinh8LiCqTST774vP2fxDSKG1G0NM_iTJyVvHtS_6Lj6bIOt8KwQ Sep 06 21:12:25 volumio volumio[899]: info: Spotify credentials grant success - running version from March 24, 2019 Sep 06 21:12:25 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:25 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:27 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:27 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:27 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:27 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:27 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:28 volumio volumio[899]: info: Initializing connection to go-librespot Websocket Sep 06 21:12:28 volumio go-librespot[9014]: time="2024-09-06T21:12:28+01:00" level=debug msg="new websocket client" Sep 06 21:12:28 volumio volumio[899]: info: Connection to go-librespot Websocket established Sep 06 21:12:28 volumio volumio[899]: info: go-librespot daemon successfully initialized Sep 06 21:12:29 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 21:12:29 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 21:12:30 volumio volumio[899]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 06 21:12:30 volumio volumio[899]: info: Received Get System Version Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 06 21:12:30 volumio volumio[899]: info: Received Get System Info Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 21:12:30 volumio volumio[899]: info: Discovery: Getting this device information Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:30 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:30 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="fetched new accesspoints: [ap2-gew1.spotify.com:4070 ap2-gew1.spotify.com:443 ap2-gew1.spotify.com:80 ap2-guc3.spotify.com:4070 ap2-gue1.spotify.com:443 ap2-gae2.spotify.com:80]" Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="zeroconf server listening on port 38919" Sep 06 21:12:31 volumio volumio[899]: info: Getting Spotify volume Sep 06 21:12:31 volumio volumio[899]: info: Initializing connection to go-librespot Websocket Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="new websocket client" Sep 06 21:12:31 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 06 21:12:31 volumio volumio[899]: info: Connection to go-librespot Websocket established Sep 06 21:12:31 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:31 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:31 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:12:31 volumio go-librespot[9014]: time="2024-09-06T21:12:31+01:00" level=debug msg="obtained new client token: AAAI0HnSWcZ6Lc+BZfzUCLLZxaUjUZ9uVJTOE806Z38TZR4Ov8TXpYgUIDoZ8G+M3+usMdWIETcsT9Fno4BKL0YUJj/K1wf4bdFSG6doHDmMYJa7hkN/RMwAOrTB2GnokMfzygu7U65G9FuPxFj01ajZm7ddKKKa1ByPJvNbyOCmMNxXEwVfjIzuHtDca3ZAkZ/EzDLFdOewsOvHq044mjIwHeu6OvbFSYfUynLX9M2vMdiib5xIqXnQ" Sep 06 21:12:32 volumio go-librespot[9014]: time="2024-09-06T21:12:32+01:00" level=debug msg="completed keyexchange" Sep 06 21:12:32 volumio go-librespot[9014]: time="2024-09-06T21:12:32+01:00" level=debug msg="completed challenge" Sep 06 21:12:33 volumio go-librespot[9014]: time="2024-09-06T21:12:33+01:00" level=debug msg="authenticated as collinskcs" Sep 06 21:12:34 volumio volumio[899]: info: Getting Spotify volume Sep 06 21:12:34 volumio volumio[899]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 06 21:12:34 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:34 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:34 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:12:36 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:36 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:37 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:37 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:37 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:37 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:37 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:37 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:37 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:37 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:39 volumio go-librespot[9014]: time="2024-09-06T21:12:39+01:00" level=debug msg="authenticated as collinskcs" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="dealer connection opened" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="stored credentials for collinskcs" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="initializing zeroconf session, username: collinskcs" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="received connection id: YTA0MDZkMTAtMDhjNi00Mjg0LTkyYTgtYTA5MTUwMTYyNjVkK2RlYWxlcit0Y3A6Ly8wYWNhNDAxYi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArNjBCQUEyOENFMjFERjE5RjJCOUFFQjEzQkE2OTNFM0JENENDOTZFQ0U3NDY3NjE4RUVCQjMyQTI4MDZCQTgwRg==" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Sep 06 21:12:40 volumio volumio[899]: info: Spotify volume: 100 Sep 06 21:12:40 volumio volumio[899]: info: Spotify volume: 100 Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="put connect state because NEW_DEVICE" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Sep 06 21:12:40 volumio go-librespot[9014]: time="2024-09-06T21:12:40+01:00" level=debug msg="autoplay enabled: false" Sep 06 21:12:45 volumio volumio[899]: error: Cannot download Available plugins list: Error: ETIMEDOUT Sep 06 21:12:46 volumio volumio[899]: Searching all installed plugins Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: , search Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 06 21:12:46 volumio volumio[899]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 06 21:12:46 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Sep 06 21:12:47 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:47 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:47 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:47 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:47 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:12:48 volumio volumio[899]: info: An error occurred while querying SHOUTCAST Sep 06 21:12:48 volumio volumio[899]: info: All search sources collected, pushing search results Sep 06 21:12:57 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:12:57 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:12:57 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:12:57 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:12:57 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:13:00 volumio volumio[899]: info: Saving local item radio-favourites Sep 06 21:13:00 volumio volumio[899]: info: Pushing Favourites {"uri":"http://opml.radiotime.com/Tune.ashx?id=s134095","favourite":false} Sep 06 21:13:03 volumio volumio[899]: error: error Sep 06 21:13:03 volumio volumio[899]: error: error Sep 06 21:13:06 volumio volumio[899]: info: Preload queue cleared Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::ClearQueue Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::stPlaybackTimer Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::updateTrackBlock Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrackBlock Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::serviceStop Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::serviceStop Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::stop Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::clearPlayQueue Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::saveQueue Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushQueue Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::addQueueItems Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::addQueueItems Sep 06 21:13:06 volumio volumio[899]: info: Preload queue cleared Sep 06 21:13:06 volumio volumio[899]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s134095 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: info: Sep 06 21:13:06 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand stop took 58 milliseconds Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:06 volumio volumio[899]: info: Sep 06 21:13:06 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:06 volumio volumio[899]: info: Sep 06 21:13:06 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand status took 9 milliseconds Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand status took 7 milliseconds Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand status took 4 milliseconds Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 21:13:06 volumio volumio[899]: info: sendMpdCommand playlistinfo took 6 milliseconds Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseTrackInfo Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseTrackInfo Sep 06 21:13:06 volumio volumio[899]: verbose: ControllerMpd::parseTrackInfo Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"All That She Wants","artist":"Ace of Base","album":"Ace Of Base - Greatest Hits","uri":"NAS/Music/Others/Ace of Base - All That She Wants.mp3","trackType":"mp3"} Sep 06 21:13:06 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState stateService stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: No code Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"All That She Wants","artist":"Ace of Base","album":"Ace Of Base - Greatest Hits","uri":"NAS/Music/Others/Ace of Base - All That She Wants.mp3","trackType":"mp3"} Sep 06 21:13:06 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState stateService stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: No code Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"All That She Wants","artist":"Ace of Base","album":"Ace Of Base - Greatest Hits","uri":"NAS/Music/Others/Ace of Base - All That She Wants.mp3","trackType":"mp3"} Sep 06 21:13:06 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState stateService stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus stop Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: No code Sep 06 21:13:06 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:06 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:06 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:06 volumio volumio[899]: info: ------------------------------ 116ms Sep 06 21:13:06 volumio volumio[899]: info: ------------------------------ 114ms Sep 06 21:13:06 volumio volumio[899]: info: ------------------------------ 114ms Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:06 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:07 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:13:07 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:07 volumio volumio[899]: info: CoreCommandRouter::volumioGetQueue Sep 06 21:13:07 volumio volumio[899]: info: CoreStateMachine::getQueue Sep 06 21:13:07 volumio volumio[899]: info: CorePlayQueue::getQueue Sep 06 21:13:10 volumio volumio[899]: info: CoreCommandRouter::volumioPushQueue Sep 06 21:13:10 volumio volumio[899]: info: CorePlayQueue::saveQueue Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::updateTrackBlock Sep 06 21:13:10 volumio volumio[899]: info: CorePlayQueue::getTrackBlock Sep 06 21:13:10 volumio volumio[899]: info: CoreCommandRouter::volumioPlay Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::play index 0 Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::stop Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::play index undefined Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 06 21:13:10 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:10 volumio volumio[899]: info: CoreStateMachine::startPlaybackTimer Sep 06 21:13:10 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:10 volumio volumio[899]: info: [1725653590404] ControllerWebradio::clearAddPlayTrack Sep 06 21:13:10 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand stop Sep 06 21:13:10 volumio volumio[899]: info: sendMpdCommand stop took 5 milliseconds Sep 06 21:13:10 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand clear Sep 06 21:13:10 volumio volumio[899]: info: Sep 06 21:13:10 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:10 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:10 volumio volumio[899]: info: sendMpdCommand clear took 3 milliseconds Sep 06 21:13:10 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand load "http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos" Sep 06 21:13:10 volumio volumio[899]: info: Sep 06 21:13:10 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:10 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:10 volumio volumio[899]: info: Sep 06 21:13:10 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:10 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:10 volumio volumio[899]: error: updateQueue error: null Sep 06 21:13:10 volumio volumio[899]: info: ------------------------------ 9ms Sep 06 21:13:13 volumio volumio[899]: error: updateQueue error: null Sep 06 21:13:13 volumio volumio[899]: error: updateQueue error: null Sep 06 21:13:13 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand add "http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos" Sep 06 21:13:13 volumio volumio[899]: info: ------------------------------ 3036ms Sep 06 21:13:13 volumio volumio[899]: info: ------------------------------ 3035ms Sep 06 21:13:13 volumio volumio[899]: info: Sep 06 21:13:13 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:13 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:13 volumio volumio[899]: info: sendMpdCommand add "http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos" took 4 milliseconds Sep 06 21:13:13 volumio volumio[899]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 06 21:13:13 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand play Sep 06 21:13:13 volumio volumio[899]: Upnp client error: Error: This socket has been ended by the other party Sep 06 21:13:13 volumio volumio[899]: info: Sep 06 21:13:13 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:13 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:13 volumio volumio[899]: info: Sep 06 21:13:13 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:13 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:13 volumio volumio[899]: info: ------------------------------ 12ms Sep 06 21:13:13 volumio volumio[899]: info: sendMpdCommand play took 10 milliseconds Sep 06 21:13:13 volumio volumio[899]: info: ------------------------------ 6ms Sep 06 21:13:13 volumio volumio[899]: info: ------------------------------ 4ms Sep 06 21:13:14 volumio volumio[899]: Searching all installed plugins Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: , search Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 06 21:13:14 volumio volumio[899]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 06 21:13:14 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Sep 06 21:13:15 volumio volumio[899]: Searching all installed plugins Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: , search Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 06 21:13:15 volumio volumio[899]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 06 21:13:15 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Sep 06 21:13:15 volumio volumio[899]: info: All search sources collected, pushing search results Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:15 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:15 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:15 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:15 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces system playlist update Sep 06 21:13:15 volumio volumio[899]: info: Ignoring MPD Status Update Sep 06 21:13:15 volumio volumio[899]: info: Sep 06 21:13:15 volumio volumio[899]: ---------------------------- MPD announces state update: player Sep 06 21:13:15 volumio volumio[899]: info: ControllerMpd::getState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand status Sep 06 21:13:15 volumio volumio[899]: info: ------------------------------ 37ms Sep 06 21:13:15 volumio volumio[899]: info: sendMpdCommand status took 35 milliseconds Sep 06 21:13:15 volumio volumio[899]: info: ------------------------------ 34ms Sep 06 21:13:15 volumio volumio[899]: info: sendMpdCommand status took 32 milliseconds Sep 06 21:13:15 volumio volumio[899]: info: ------------------------------ 31ms Sep 06 21:13:15 volumio volumio[899]: info: sendMpdCommand status took 14 milliseconds Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::parseState Sep 06 21:13:15 volumio volumio[899]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 06 21:13:16 volumio volumio[899]: info: sendMpdCommand playlistinfo took 43 milliseconds Sep 06 21:13:16 volumio volumio[899]: info: sendMpdCommand playlistinfo took 44 milliseconds Sep 06 21:13:16 volumio volumio[899]: verbose: ControllerMpd::parseTrackInfo Sep 06 21:13:16 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:16 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:16 volumio volumio[899]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"TIMEX SOCIAL CLUB - RUMOURS","artist":null,"album":null,"uri":"http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos","trackType":""} Sep 06 21:13:16 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState stateService play Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus stop Sep 06 21:13:16 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:16 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:16 volumio volumio[899]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"TIMEX SOCIAL CLUB - RUMOURS","artist":null,"album":null,"uri":"http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos","trackType":""} Sep 06 21:13:16 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState stateService play Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus play Sep 06 21:13:16 volumio volumio[899]: info: Received an update from plugin. extracting info from payload Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:16 volumio volumio[899]: info: ControllerMpd::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::servicePushState Sep 06 21:13:16 volumio volumio[899]: info: CorePlayQueue::getTrack 0 Sep 06 21:13:16 volumio volumio[899]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"TIMEX SOCIAL CLUB - RUMOURS","artist":null,"album":null,"uri":"http://classicfmlagos.atunwadigital.streamguys1.com/classicfmlagos","trackType":""} Sep 06 21:13:16 volumio volumio[899]: verbose: CURRENT POSITION 0 Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState stateService play Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::syncState currentStatus play Sep 06 21:13:16 volumio volumio[899]: info: Received an update from plugin. extracting info from payload Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:16 volumio volumio[899]: info: CoreStateMachine::pushState Sep 06 21:13:16 volumio volumio[899]: info: CoreCommandRouter::volumioPushState Sep 06 21:13:16 volumio volumio[899]: info: ------------------------------ 124ms Sep 06 21:13:16 volumio volumio[899]: info: ------------------------------ 146ms Sep 06 21:13:16 volumio volumio[899]: info: ------------------------------ 129ms Sep 06 21:13:16 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:16 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:16 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:16 volumio volumio[899]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Sep 06 21:13:17 volumio volumio[899]: info: All search sources collected, pushing search results Sep 06 21:13:17 volumio volumio[899]: info: CoreCommandRouter::volumioGetState Sep 06 21:13:17 volumio volumio[899]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg' Sep 06 21:13:18 volumio volumio[899]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg' Sep 06 21:13:20 volumio volumio[899]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 21:13:20 volumio volumio[899]: Error: connect ETIMEDOUT 151.101.2.79:80 Sep 06 21:13:20 volumio volumio[899]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Sep 06 21:13:20 volumio volumio[899]: errno: -110, Sep 06 21:13:20 volumio volumio[899]: code: 'ETIMEDOUT', Sep 06 21:13:20 volumio volumio[899]: syscall: 'connect', Sep 06 21:13:20 volumio volumio[899]: address: '151.101.2.79', Sep 06 21:13:20 volumio volumio[899]: port: 80 Sep 06 21:13:20 volumio volumio[899]: } Sep 06 21:13:20 volumio volumio[899]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 21:13:21 volumio sudo[9177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-09-06 21:12 Sep 06 21:13:21 volumio sudo[9177]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"