-- Logs begin at Tue 2024-07-09 15:33:33 -03, end at Wed 2024-07-10 06:16:38 -03. -- Jul 10 06:15:14 volumio systemd[1]: Starting Daily man-db regeneration... Jul 10 06:15:14 volumio systemd[1]: Starting Daily apt download activities... Jul 10 06:15:15 volumio systemd[1]: man-db.service: Succeeded. Jul 10 06:15:15 volumio systemd[1]: Started Daily man-db regeneration. Jul 10 06:15:16 volumio volumio[1162]: .......................................................................................................................................++++ Jul 10 06:15:16 volumio volumio[1162]: e is 65537 (0x010001) Jul 10 06:15:16 volumio volumio[1162]: writing RSA key Jul 10 06:15:17 volumio go-librespot[1488]: time="2024-07-10T06:15:17-03:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 10 06:15:17 volumio ntpd[743]: Soliciting pool server 200.160.7.196 Jul 10 06:15:17 volumio ntpd[743]: Soliciting pool server 192.36.143.130 Jul 10 06:15:17 volumio go-librespot[1488]: time="2024-07-10T06:15:17-03:00" level=debug msg="completed keyexchange" Jul 10 06:15:17 volumio volumio[814]: error: MyVolumio Custom Token format not valid, refreshing it Jul 10 06:15:17 volumio nmbd[725]: [2024/07/10 06:15:17.766367, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jul 10 06:15:17 volumio nmbd[725]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.2.19 for name WORKGROUP<1d>. Jul 10 06:15:17 volumio nmbd[725]: This response was from IP 192.168.2.86, reporting an IP address of 192.168.2.86. Jul 10 06:15:17 volumio go-librespot[1488]: time="2024-07-10T06:15:17-03:00" level=debug msg="completed challenge" Jul 10 06:15:18 volumio go-librespot[1488]: time="2024-07-10T06:15:18-03:00" level=debug msg="authenticated as frannciscorj" Jul 10 06:15:18 volumio systemd[1]: apt-daily.service: Succeeded. Jul 10 06:15:18 volumio systemd[1]: Started Daily apt download activities. Jul 10 06:15:22 volumio python[721]: 8.8.8.8 is still not reachable, trying again in 1 sec Jul 10 06:15:25 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 10 06:15:25 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jul 10 06:15:25 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:25 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:26 volumio volumio[814]: info: Discovery: A device disappeared from network Jul 10 06:15:26 volumio volumio[814]: info: Discovery: Device volumio disappeared from network Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::volumioGetBrowseSources Jul 10 06:15:30 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 10 06:15:33 volumio python[721]: 8.8.8.8 is still not reachable, trying again in 1 sec Jul 10 06:15:42 volumio volumio[814]: info: Discovery: adding 9f23fbe4-de09-4992-be08-ac6838bf1860 Jul 10 06:15:42 volumio volumio[814]: info: Discovery: Found device Volumio Jul 10 06:15:42 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:42 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:44 volumio python[721]: 8.8.8.8 is still not reachable, trying again in 1 sec Jul 10 06:15:48 volumio go-librespot[1488]: time="2024-07-10T06:15:48-03:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed requesting login5 endpoint: failed requesting login5: Post \"https://login5.spotify.com/v3/login\": dial tcp 35.186.224.24:443: i/o timeout" Jul 10 06:15:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 10 06:15:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 10 06:15:48 volumio volumio[814]: (node:814) UnhandledPromiseRejectionWarning: Error: socket hang up Jul 10 06:15:48 volumio volumio[814]: at connResetException (internal/errors.js:607:14) Jul 10 06:15:48 volumio volumio[814]: at Socket.socketOnEnd (_http_client.js:493:23) Jul 10 06:15:48 volumio volumio[814]: at Socket.emit (events.js:327:22) Jul 10 06:15:48 volumio volumio[814]: at endReadableNT (internal/streams/readable.js:1327:12) Jul 10 06:15:48 volumio volumio[814]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jul 10 06:15:48 volumio volumio[814]: (node:814) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Jul 10 06:15:48 volumio volumio[814]: info: Connection to go-librespot Websocket closed Jul 10 06:15:51 volumio volumio[814]: info: Initializing connection to go-librespot Websocket Jul 10 06:15:51 volumio volumio[814]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jul 10 06:15:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jul 10 06:15:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 10 06:15:51 volumio systemd[1]: Stopped go-librespot Daemon. Jul 10 06:15:51 volumio systemd[1]: Started go-librespot Daemon. Jul 10 06:15:51 volumio go-librespot[1714]: Librespot-go daemon starting... Jul 10 06:15:51 volumio go-librespot[1714]: time="2024-07-10T06:15:51-03:00" level=info msg="generated new device id: e4878fb8ea56b6cd2f41ad97eafb793bdf853263" Jul 10 06:15:51 volumio go-librespot[1714]: time="2024-07-10T06:15:51-03:00" level=debug msg="stored credentials found for frannciscorj" Jul 10 06:15:54 volumio volumio[814]: info: Initializing connection to go-librespot Websocket Jul 10 06:15:54 volumio go-librespot[1714]: time="2024-07-10T06:15:54-03:00" level=debug msg="new websocket client" Jul 10 06:15:54 volumio volumio[814]: info: Connection to go-librespot Websocket established Jul 10 06:15:55 volumio python[721]: 8.8.8.8 is still not reachable, trying again in 1 sec Jul 10 06:15:56 volumio python[721]: 8.8.8.8 is reachable again, resuming Volumio playback now Jul 10 06:15:56 volumio python[721]: Starting Volumio playback... Jul 10 06:15:56 volumio python[721]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 10 06:15:56 volumio python[721]: Dload Upload Total Spent Left Speed Jul 10 06:15:56 volumio volumio[814]: info: Jul 10 06:15:56 volumio volumio[814]: ---------------------------- Client requests Volumio play Jul 10 06:15:56 volumio volumio[814]: info: CoreCommandRouter::volumioPlay Jul 10 06:15:56 volumio volumio[814]: info: CoreStateMachine::play index undefined Jul 10 06:15:56 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 10 06:15:56 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:56 volumio volumio[814]: info: CoreStateMachine::startPlaybackTimer Jul 10 06:15:56 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:56 volumio volumio[814]: info: [1720602956674] ControllerWebradio::clearAddPlayTrack Jul 10 06:15:56 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Jul 10 06:15:56 volumio volumio[814]: info: sendMpdCommand stop took 4 milliseconds Jul 10 06:15:56 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand clear Jul 10 06:15:56 volumio python[721]: [158B blob data] Jul 10 06:15:56 volumio volumio[814]: info: sendMpdCommand clear took 1 milliseconds Jul 10 06:15:56 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand load "https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4" Jul 10 06:15:56 volumio volumio[814]: info: Jul 10 06:15:56 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:15:56 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:15:56 volumio volumio[814]: info: Jul 10 06:15:56 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:15:56 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:15:56 volumio volumio[814]: info: Jul 10 06:15:56 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:15:56 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:15:56 volumio volumio[814]: error: Upnp client error: Error: This socket has been ended by the other party Jul 10 06:15:57 volumio volumio[814]: info: Getting Spotify volume Jul 10 06:15:57 volumio volumio[814]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jul 10 06:15:57 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:57 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:57 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:57 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:57 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:57 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:58 volumio volumio[814]: info: MyVolumio login type: Token Jul 10 06:15:58 volumio go-librespot[1714]: time="2024-07-10T06:15:58-03:00" level=debug msg="obtained new client token: AAA6ehEkcCL1PihEAFaqjaaVRVEmYTO7Y+jXmUpByUaOdBaVXCnR2CnJE4UKJOcE7X1SNTAqMZR/zRjhe2ztygH3kkLKn24Qp1GSjT9iCobJCpxNCDPR/G+g8vQEfF+hwJKbjhNt22BRZjNfGk6eQcPSVp47ETyx7dPfjd2TyvLtEDRampskkCZUPWxlSgqV4Jv0s09Mixp3c/Z2t581dzpf26t/NvI5/6xDtyQxZ3KxxsN3ng/Rf7RMhDzYYo8r3Q==" Jul 10 06:15:58 volumio go-librespot[1714]: time="2024-07-10T06:15:58-03:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 10 06:15:58 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:58 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:58 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:15:58 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:15:59 volumio go-librespot[1714]: time="2024-07-10T06:15:59-03:00" level=debug msg="completed keyexchange" Jul 10 06:15:59 volumio volumio[814]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jul 10 06:15:59 volumio go-librespot[1714]: time="2024-07-10T06:15:59-03:00" level=debug msg="completed challenge" Jul 10 06:15:59 volumio go-librespot[1714]: time="2024-07-10T06:15:59-03:00" level=debug msg="authenticated as frannciscorj" Jul 10 06:15:59 volumio volumio[814]: info: MyVolumio token set successfully Jul 10 06:15:59 volumio volumio[814]: info: MYVOLUMIO: Adding device Jul 10 06:15:59 volumio volumio[814]: info: MYVOLUMIO: Evaluating Server Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="authenticated as frannciscorj" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 10 06:16:00 volumio volumio[814]: info: MyVolumio status changed Jul 10 06:16:00 volumio volumio[814]: info: Streaming services startup Jul 10 06:16:00 volumio volumio[814]: info: Starting Streaming Daemon Jul 10 06:16:00 volumio volumio[814]: info: Removing browser output: myVolumio user plan is not superstar Jul 10 06:16:00 volumio volumio[814]: info: Removing audio output: Jul 10 06:16:00 volumio volumio[814]: info: Stoppping Tunnel 1 Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 10 06:16:00 volumio sudo[1779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 10 06:16:00 volumio sudo[1779]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 10 06:16:00 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:00 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:00 volumio sudo[1779]: pam_unix(sudo:session): session closed for user root Jul 10 06:16:00 volumio sudo[1781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jul 10 06:16:00 volumio sudo[1781]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 10 06:16:00 volumio volumio[814]: error: Cannot start Volumio Streaming Daemon Jul 10 06:16:00 volumio volumio[814]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jul 10 06:16:00 volumio volumio[814]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jul 10 06:16:00 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:00 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:00 volumio sudo[1781]: pam_unix(sudo:session): session closed for user root Jul 10 06:16:00 volumio volumio[814]: info: Remote SSH Stopped Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="dealer connection opened" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="received connection id: NGE2NzAzZjQtNDBiMy00MTA3LWI3MTItMWM2ZGJlNTJkYTdmK2RlYWxlcit0Y3A6Ly9ndWUxLWRlYWxlci1hLXQ4eHQuZ3VlMS5zcG90aWZ5Lm5ldDo1NzAwKzI3RTIzNEM1MjI0RTBDRUYyOEY3NjgzNTM5QkNDNDE3RDhDMkJDRDlGMjlGMDgxOTUyNzQ4RkEyMzExQzlCMzA=" Jul 10 06:16:00 volumio volumio[814]: info: Spotify volume: 100 Jul 10 06:16:00 volumio go-librespot[1714]: time="2024-07-10T06:16:00-03:00" level=debug msg="put connect state because NEW_DEVICE" Jul 10 06:16:00 volumio volumio[814]: info: Setting Geolocation for MyVolumio to us1 Jul 10 06:16:00 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:00 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:00 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:01 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand add "https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4" Jul 10 06:16:01 volumio volumio[814]: error: updateQueue error: null Jul 10 06:16:01 volumio volumio[814]: error: updateQueue error: null Jul 10 06:16:01 volumio volumio[814]: info: Jul 10 06:16:01 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:01 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 4874ms Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 4872ms Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 4871ms Jul 10 06:16:01 volumio volumio[814]: info: sendMpdCommand add "https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4" took 5 milliseconds Jul 10 06:16:01 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 10 06:16:01 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand play Jul 10 06:16:01 volumio volumio[814]: Upnp client error: Error: This socket has been ended by the other party Jul 10 06:16:01 volumio volumio[814]: info: Jul 10 06:16:01 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:01 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:01 volumio volumio[814]: info: Jul 10 06:16:01 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:01 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 10ms Jul 10 06:16:01 volumio volumio[814]: info: sendMpdCommand play took 8 milliseconds Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 6ms Jul 10 06:16:01 volumio volumio[814]: info: ------------------------------ 4ms Jul 10 06:16:01 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:01 volumio volumio[814]: info: Updating MyVolumio device info Jul 10 06:16:01 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:01 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:01 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:02 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:03 volumio ntpd[743]: Soliciting pool server 200.160.7.193 Jul 10 06:16:03 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:04 volumio ntpd[743]: Soliciting pool server 200.189.40.8 Jul 10 06:16:04 volumio ntpd[743]: Soliciting pool server 200.160.7.196 Jul 10 06:16:04 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:05 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:06 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:07 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 10 06:16:08 volumio volumio[814]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 10 06:16:08 volumio volumio[814]: info: Received Get System Version Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 10 06:16:08 volumio volumio[814]: info: Received Get System Info Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 10 06:16:08 volumio volumio[814]: info: Discovery: Getting this device information Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:08 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 10 06:16:09 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:09 volumio volumio[814]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jul 10 06:16:09 volumio volumio[814]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jul 10 06:16:10 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:11 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:12 volumio ntpd[743]: Soliciting pool server 185.234.20.131 Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 47 milliseconds Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 50 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 49 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:12 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus stop Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 63ms Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 24ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 23 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand playlistinfo took 21 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand playlistinfo took 26 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 21ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 17 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:12 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:12 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:12 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:12 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 189ms Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 188ms Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:12 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:12 volumio volumio[814]: info: Jul 10 06:16:12 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 136ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 134 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 131ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 121 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand playlistinfo took 120 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand playlistinfo took 119 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 13ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 11 milliseconds Jul 10 06:16:12 volumio volumio[814]: info: ------------------------------ 10ms Jul 10 06:16:12 volumio volumio[814]: info: sendMpdCommand status took 9 milliseconds Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:12 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":182,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:12 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:12 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:12 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:12 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":457,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:12 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:12 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:12 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:12 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 288ms Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 277ms Jul 10 06:16:13 volumio volumio[814]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Radio Cidade Jul 10 06:16:13 volumio volumio[814]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! Radio Cidade Jul 10 06:16:13 volumio volumio[814]: info: [LastFM] Split composite title into artist: NEW ORDER and title: REGRET Jul 10 06:16:13 volumio volumio[814]: info: [LastFM] Split composite title into artist: NEW ORDER and title: REGRET Jul 10 06:16:13 volumio volumio[814]: info: sendMpdCommand playlistinfo took 229 milliseconds Jul 10 06:16:13 volumio volumio[814]: info: sendMpdCommand playlistinfo took 228 milliseconds Jul 10 06:16:13 volumio volumio[814]: info: sendMpdCommand playlistinfo took 225 milliseconds Jul 10 06:16:13 volumio volumio[814]: info: sendMpdCommand playlistinfo took 225 milliseconds Jul 10 06:16:13 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:13 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:13 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:13 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:13 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:13 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":731,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:13 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:13 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:13 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":845,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:13 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:13 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:13 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1028,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:13 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:13 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:13 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:13 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1028,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:13 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:13 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 541ms Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 537ms Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 419ms Jul 10 06:16:13 volumio volumio[814]: info: ------------------------------ 416ms Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:13 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:13 volumio volumio[814]: info: MYVOLUMIO: Adding device Jul 10 06:16:13 volumio volumio[814]: info: MYVOLUMIO: Evaluating Server Jul 10 06:16:18 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Regret","mbid":"44618738-de03-4297-957a-df84cb113c7b","url":"https://www.last.fm/music/New+Order/_/Regret","duration":"249000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"295585","playcount":"1519069","artist":{"name":"New Order","mbid":"f1106b17-dcbb-45f6-b938-199ccfab50cc","url":"https://www.last.fm/music/New+Order"},"album":{"@":{"position":"1"},"artist":"New Order","title":"Republic","mbid":"0fda76fb-e002-4bb3-89fa-050c766d4f82","url":"https://www.last.fm/music/New+Order/Republic","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"extralarge"}}]},"userplaycount":"20","userloved":"0","toptags":{"tag":[{"name":"new wave","url":"https://www.last.fm/tag/new+wave"},{"name":"80s","url":"https://www.last.fm/tag/80s"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"90s","url":"https://www.last.fm/tag/90s"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"}]},"wiki":{"published":"11 Jan 2009, 02:22","summary":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart Read more on Last.fm.","content":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart, a very rare occurrence of a song being accepted on both rock and dance charts. It also peaked at a modest #28 on the Billboard Hot 100 becoming the band's biggest hit in the United States. The song made an impressive showing on the UK Singles Chart, peaking at #4. The B-sides differed on the various releases in different formats and countries; all were remixes, including the Fire Island Mix and Junior Dub by Pete Heller and Terry Farley and various Sabres of Paradise mixes. A music video was also produced for the song, directed by Peter Care and it appears on the \"Regret\" promotional VHS, as well as A Collection. The video also appears in the PSP game Lumines II. The song was also covered by the American rock band The Get Up Kids and released on their compilation album Eudora in 2001. The band filmed a memorable performance of the song for Top of the Pops from the beach where Baywatch was filmed, featuring David Hasselhoff and various extras in the background. The band initially wanted to have David mime along to the song too, but the producers of Baywatch wouldn't let them. The song is one of very few which have topped both the US rock and Dance charts, the general differences between these genres being rarely bridged. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Jul 10 06:16:18 volumio volumio[814]: info: [LastFM] Updated missing track duration: 249000 Jul 10 06:16:18 volumio volumio[814]: info: [LastFM] Updated missing track album: Republic Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:26 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:26 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:26 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:26 volumio volumio[814]: info: Jul 10 06:16:26 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 9ms Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand status took 8 milliseconds Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 7ms Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand status took 6 milliseconds Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 5ms Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand status took 4 milliseconds Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:26 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:26 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:26 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:26 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":14657,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:26 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:26 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:26 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:26 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":14657,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:26 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:26 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:26 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:26 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":14657,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"NEW ORDER - REGRET","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:26 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:26 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:26 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 140ms Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 138ms Jul 10 06:16:26 volumio volumio[814]: info: ------------------------------ 137ms Jul 10 06:16:26 volumio volumio[814]: info: [LastFM] Split composite title into artist: NEW ORDER and title: REGRET Jul 10 06:16:26 volumio volumio[814]: info: [LastFM] Split composite title into artist: NEW ORDER and title: REGRET Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:27 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:27 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:27 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:27 volumio volumio[814]: info: Jul 10 06:16:27 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 9ms Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand status took 8 milliseconds Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 7ms Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand status took 5 milliseconds Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 5ms Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand status took 4 milliseconds Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:27 volumio volumio[814]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:27 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:27 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:27 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":15275,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"COLDPLAY - GOD PUT A SMILE UPON YOUR FACE","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:27 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:27 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:27 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:27 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":15275,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"COLDPLAY - GOD PUT A SMILE UPON YOUR FACE","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:27 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:27 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:27 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:27 volumio volumio[814]: verbose: STATE SERVICE {"status":"play","position":0,"seek":15275,"duration":0,"samplerate":"22.05 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"64 Kbps","isStreaming":false,"title":"COLDPLAY - GOD PUT A SMILE UPON YOUR FACE","artist":null,"album":null,"uri":"https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4","trackType":""} Jul 10 06:16:27 volumio volumio[814]: verbose: CURRENT POSITION 0 Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState stateService play Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::syncState currentStatus play Jul 10 06:16:27 volumio volumio[814]: info: Received an update from plugin. extracting info from payload Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:27 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 135ms Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 133ms Jul 10 06:16:27 volumio volumio[814]: info: ------------------------------ 132ms Jul 10 06:16:27 volumio volumio[814]: info: [LastFM] Split composite title into artist: COLDPLAY and title: GOD PUT A SMILE UPON YOUR FACE Jul 10 06:16:27 volumio volumio[814]: info: [LastFM] Split composite title into artist: COLDPLAY and title: GOD PUT A SMILE UPON YOUR FACE Jul 10 06:16:27 volumio volumio[814]: [LastFM] updated "now playing" failed: { Jul 10 06:16:27 volumio volumio[814]: success: false, Jul 10 06:16:27 volumio volumio[814]: error: 'Invalid parameters - Your request is missing a required parameter' Jul 10 06:16:27 volumio volumio[814]: } Jul 10 06:16:27 volumio volumio[814]: info: An error occurred while refreshing Spotify Token Error: connect ETIMEDOUT 66.241.124.99:443 Jul 10 06:16:27 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Regret","mbid":"44618738-de03-4297-957a-df84cb113c7b","url":"https://www.last.fm/music/New+Order/_/Regret","duration":"249000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"295585","playcount":"1519069","artist":{"name":"New Order","mbid":"f1106b17-dcbb-45f6-b938-199ccfab50cc","url":"https://www.last.fm/music/New+Order"},"album":{"@":{"position":"1"},"artist":"New Order","title":"Republic","mbid":"0fda76fb-e002-4bb3-89fa-050c766d4f82","url":"https://www.last.fm/music/New+Order/Republic","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"extralarge"}}]},"userplaycount":"20","userloved":"0","toptags":{"tag":[{"name":"new wave","url":"https://www.last.fm/tag/new+wave"},{"name":"80s","url":"https://www.last.fm/tag/80s"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"90s","url":"https://www.last.fm/tag/90s"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"}]},"wiki":{"published":"11 Jan 2009, 02:22","summary":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart Read more on Last.fm.","content":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart, a very rare occurrence of a song being accepted on both rock and dance charts. It also peaked at a modest #28 on the Billboard Hot 100 becoming the band's biggest hit in the United States. The song made an impressive showing on the UK Singles Chart, peaking at #4. The B-sides differed on the various releases in different formats and countries; all were remixes, including the Fire Island Mix and Junior Dub by Pete Heller and Terry Farley and various Sabres of Paradise mixes. A music video was also produced for the song, directed by Peter Care and it appears on the \"Regret\" promotional VHS, as well as A Collection. The video also appears in the PSP game Lumines II. The song was also covered by the American rock band The Get Up Kids and released on their compilation album Eudora in 2001. The band filmed a memorable performance of the song for Top of the Pops from the beach where Baywatch was filmed, featuring David Hasselhoff and various extras in the background. The band initially wanted to have David mime along to the song too, but the producers of Baywatch wouldn't let them. The song is one of very few which have topped both the US rock and Dance charts, the general differences between these genres being rarely bridged. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Jul 10 06:16:27 volumio volumio[814]: info: [LastFM] Updated missing track duration: 249000 Jul 10 06:16:27 volumio volumio[814]: info: [LastFM] Updated missing track album: Republic Jul 10 06:16:28 volumio volumio[814]: info: Setting Geolocation for MyVolumio to eu3 Jul 10 06:16:28 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:28 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:28 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:29 volumio volumio[814]: info: Updating MyVolumio device info Jul 10 06:16:29 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:29 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:29 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 10 06:16:31 volumio volumio[814]: [LastFM] updated "now playing" failed: { Jul 10 06:16:31 volumio volumio[814]: success: false, Jul 10 06:16:31 volumio volumio[814]: error: 'Invalid parameters - Your request is missing a required parameter' Jul 10 06:16:31 volumio volumio[814]: } Jul 10 06:16:31 volumio volumio[814]: [LastFM] updated "now playing" failed: { Jul 10 06:16:31 volumio volumio[814]: success: false, Jul 10 06:16:31 volumio volumio[814]: error: 'Invalid parameters - Your request is missing a required parameter' Jul 10 06:16:31 volumio volumio[814]: } Jul 10 06:16:31 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Regret","mbid":"44618738-de03-4297-957a-df84cb113c7b","url":"https://www.last.fm/music/New+Order/_/Regret","duration":"249000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"295585","playcount":"1519069","artist":{"name":"New Order","mbid":"f1106b17-dcbb-45f6-b938-199ccfab50cc","url":"https://www.last.fm/music/New+Order"},"album":{"@":{"position":"1"},"artist":"New Order","title":"Republic","mbid":"0fda76fb-e002-4bb3-89fa-050c766d4f82","url":"https://www.last.fm/music/New+Order/Republic","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"extralarge"}}]},"userplaycount":"20","userloved":"0","toptags":{"tag":[{"name":"new wave","url":"https://www.last.fm/tag/new+wave"},{"name":"80s","url":"https://www.last.fm/tag/80s"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"90s","url":"https://www.last.fm/tag/90s"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"}]},"wiki":{"published":"11 Jan 2009, 02:22","summary":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart Read more on Last.fm.","content":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart, a very rare occurrence of a song being accepted on both rock and dance charts. It also peaked at a modest #28 on the Billboard Hot 100 becoming the band's biggest hit in the United States. The song made an impressive showing on the UK Singles Chart, peaking at #4. The B-sides differed on the various releases in different formats and countries; all were remixes, including the Fire Island Mix and Junior Dub by Pete Heller and Terry Farley and various Sabres of Paradise mixes. A music video was also produced for the song, directed by Peter Care and it appears on the \"Regret\" promotional VHS, as well as A Collection. The video also appears in the PSP game Lumines II. The song was also covered by the American rock band The Get Up Kids and released on their compilation album Eudora in 2001. The band filmed a memorable performance of the song for Top of the Pops from the beach where Baywatch was filmed, featuring David Hasselhoff and various extras in the background. The band initially wanted to have David mime along to the song too, but the producers of Baywatch wouldn't let them. The song is one of very few which have topped both the US rock and Dance charts, the general differences between these genres being rarely bridged. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Jul 10 06:16:31 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"God Put a Smile Upon Your Face","mbid":"fe9caa6d-00b3-4896-ba6e-32d9e5ba2118","url":"https://www.last.fm/music/Coldplay/_/God+Put+a+Smile+Upon+Your+Face","duration":"298000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"888827","playcount":"5300396","artist":{"name":"Coldplay","mbid":"cc197bad-dc9c-440d-a5b5-d52ba2e14234","url":"https://www.last.fm/music/Coldplay"},"album":{"@":{"position":"3"},"artist":"Coldplay","title":"A Rush of Blood to the Head","mbid":"219b202d-290e-3960-b626-bf852a63bc50","url":"https://www.last.fm/music/Coldplay/A+Rush+of+Blood+to+the+Head","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"extralarge"}}]},"userplaycount":"13","userloved":"0","toptags":{"tag":[{"name":"rock","url":"https://www.last.fm/tag/rock"},{"name":"Coldplay","url":"https://www.last.fm/tag/Coldplay"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"britpop","url":"https://www.last.fm/tag/britpop"},{"name":"british","url":"https://www.last.fm/tag/british"}]}}} Jul 10 06:16:31 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"God Put a Smile Upon Your Face","mbid":"fe9caa6d-00b3-4896-ba6e-32d9e5ba2118","url":"https://www.last.fm/music/Coldplay/_/God+Put+a+Smile+Upon+Your+Face","duration":"298000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"888827","playcount":"5300396","artist":{"name":"Coldplay","mbid":"cc197bad-dc9c-440d-a5b5-d52ba2e14234","url":"https://www.last.fm/music/Coldplay"},"album":{"@":{"position":"3"},"artist":"Coldplay","title":"A Rush of Blood to the Head","mbid":"219b202d-290e-3960-b626-bf852a63bc50","url":"https://www.last.fm/music/Coldplay/A+Rush+of+Blood+to+the+Head","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/3d3d6d2b41544f42b8f750b6abdbd180.png","@":{"size":"extralarge"}}]},"userplaycount":"13","userloved":"0","toptags":{"tag":[{"name":"rock","url":"https://www.last.fm/tag/rock"},{"name":"Coldplay","url":"https://www.last.fm/tag/Coldplay"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"britpop","url":"https://www.last.fm/tag/britpop"},{"name":"british","url":"https://www.last.fm/tag/british"}]}}} Jul 10 06:16:33 volumio python[721]: {"time":1720602956672,"response":"play Success"}8.8.8.8 is not reachable (2 subsequently dropped packets), stopping Volumio playback Jul 10 06:16:33 volumio python[721]: Stopping Volumio playback... Jul 10 06:16:33 volumio python[721]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 10 06:16:33 volumio python[721]: Dload Upload Total Spent Left Speed Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- Client requests Volumio stop Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioStop Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::stop Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::stPlaybackTimer Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::updateTrackBlock Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrackBlock Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::serviceStop Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::serviceStop Jul 10 06:16:33 volumio volumio[814]: info: [1720602993564] ControllerWebradio::stop Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Jul 10 06:16:33 volumio volumio[814]: [LastFM] updated "now playing" failed: { Jul 10 06:16:33 volumio volumio[814]: success: false, Jul 10 06:16:33 volumio volumio[814]: error: 'Invalid parameters - Your request is missing a required parameter' Jul 10 06:16:33 volumio volumio[814]: } Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand stop took 54 milliseconds Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:33 volumio python[721]: [158B blob data] Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces state update: player Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::getState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand status Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand status took 14 milliseconds Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand status took 8 milliseconds Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand status took 5 milliseconds Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseState Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:33 volumio python[721]: {"time":1720602993541,"response":"stop Success"}8.8.8.8 is reachable again, resuming Volumio playback now Jul 10 06:16:33 volumio python[721]: Starting Volumio playback... Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::parseTrackInfo Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jul 10 06:16:33 volumio volumio[814]: info: ControllerMpd::pushState Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::servicePushState Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::pushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioPushState Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jul 10 06:16:33 volumio python[721]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 10 06:16:33 volumio python[721]: Dload Upload Total Spent Left Speed Jul 10 06:16:33 volumio volumio[814]: info: ------------------------------ 97ms Jul 10 06:16:33 volumio volumio[814]: info: ------------------------------ 91ms Jul 10 06:16:33 volumio volumio[814]: info: ------------------------------ 89ms Jul 10 06:16:33 volumio volumio[814]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Regret","mbid":"44618738-de03-4297-957a-df84cb113c7b","url":"https://www.last.fm/music/New+Order/_/Regret","duration":"249000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"295585","playcount":"1519069","artist":{"name":"New Order","mbid":"f1106b17-dcbb-45f6-b938-199ccfab50cc","url":"https://www.last.fm/music/New+Order"},"album":{"@":{"position":"1"},"artist":"New Order","title":"Republic","mbid":"0fda76fb-e002-4bb3-89fa-050c766d4f82","url":"https://www.last.fm/music/New+Order/Republic","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/eebfa1b56d4f3354f544c87dbf653c09.png","@":{"size":"extralarge"}}]},"userplaycount":"20","userloved":"0","toptags":{"tag":[{"name":"new wave","url":"https://www.last.fm/tag/new+wave"},{"name":"80s","url":"https://www.last.fm/tag/80s"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"90s","url":"https://www.last.fm/tag/90s"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"}]},"wiki":{"published":"11 Jan 2009, 02:22","summary":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart Read more on Last.fm.","content":"\"Regret\" was a single released by New Order in April 1993. \"Regret\" was the first song pulled from their album of the same year, Republic, for release as a single and was their first single relased under London Records following the collapse of Factory Records. It was produced by Stephen Hague, who also received a co-writing credit. \"Regret\" is generally regarded as one of the band's finest singles. In the United States, the song had two #1 terms on the Modern Rock Tracks chart and also topped the Hot Dance Music/Club Play chart, a very rare occurrence of a song being accepted on both rock and dance charts. It also peaked at a modest #28 on the Billboard Hot 100 becoming the band's biggest hit in the United States. The song made an impressive showing on the UK Singles Chart, peaking at #4. The B-sides differed on the various releases in different formats and countries; all were remixes, including the Fire Island Mix and Junior Dub by Pete Heller and Terry Farley and various Sabres of Paradise mixes. A music video was also produced for the song, directed by Peter Care and it appears on the \"Regret\" promotional VHS, as well as A Collection. The video also appears in the PSP game Lumines II. The song was also covered by the American rock band The Get Up Kids and released on their compilation album Eudora in 2001. The band filmed a memorable performance of the song for Top of the Pops from the beach where Baywatch was filmed, featuring David Hasselhoff and various extras in the background. The band initially wanted to have David mime along to the song too, but the producers of Baywatch wouldn't let them. The song is one of very few which have topped both the US rock and Dance charts, the general differences between these genres being rarely bridged. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Jul 10 06:16:33 volumio volumio[814]: info: touch_display: Setting screensaver timeout to 120 seconds. Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- Client requests Volumio play Jul 10 06:16:33 volumio volumio[814]: info: CoreCommandRouter::volumioPlay Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::play index undefined Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: CoreStateMachine::startPlaybackTimer Jul 10 06:16:33 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:33 volumio volumio[814]: info: [1720602993765] ControllerWebradio::clearAddPlayTrack Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand stop Jul 10 06:16:33 volumio python[721]: [158B blob data] Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand stop took 4 milliseconds Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand clear Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:33 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:33 volumio volumio[814]: info: sendMpdCommand clear took 2 milliseconds Jul 10 06:16:33 volumio volumio[814]: verbose: ControllerMpd::sendMpdCommand load "https://playerservices.streamtheworld.com/api/livestream-redirect/RADIOCIDADE.mp3?DIST=TuneIn&TGT=TuneIn&maxServers=2&partnertok=eyJhbGciOiJIUzI1NiIsImtpZCI6InR1bmVpbiIsInR5cCI6IkpXVCJ9.eyJ0cnVzdGVkX3BhcnRuZXIiOnRydWUsImlhdCI6MTcxNzAxMzU0OSwiaXNzIjoidGlzcnYifQ.BdWhEUiCp0neD-c4FZ7UWHg76nfsZ62ndv8vvY9rrI4" Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:33 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:33 volumio volumio[814]: info: Jul 10 06:16:33 volumio volumio[814]: ---------------------------- MPD announces system playlist update Jul 10 06:16:33 volumio volumio[814]: info: Ignoring MPD Status Update Jul 10 06:16:33 volumio volumio[814]: error: updateQueue error: null Jul 10 06:16:33 volumio volumio[814]: info: ------------------------------ 10ms Jul 10 06:16:34 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:34 volumio volumio[814]: info: CoreCommandRouter::volumioGetState Jul 10 06:16:34 volumio volumio[814]: info: CorePlayQueue::getTrack 0 Jul 10 06:16:37 volumio volumio[814]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=3.703&uuid=1de0ee1fe9ddd25447f6bbeb2afe43b2" http://updates.volumio.org/downloader-v1/track-device Jul 10 06:16:37 volumio volumio[814]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 10 06:16:37 volumio volumio[814]: Dload Upload Total Spent Left Speed Jul 10 06:16:37 volumio volumio[814]: [10.8K blob data] Jul 10 06:16:37 volumio volumio[814]: curl: (28) Failed to connect to updates.volumio.org port 80: Connection timed out Jul 10 06:16:37 volumio volumio[814]: retrying in 5 seconds, trial 0 Jul 10 06:16:37 volumio volumio[814]: info: Volumio Calling Home Jul 10 06:16:37 volumio volumio[814]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 10 06:16:37 volumio volumio[814]: Error: connect ETIMEDOUT 130.211.19.189:80 Jul 10 06:16:37 volumio volumio[814]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Jul 10 06:16:37 volumio volumio[814]: errno: -110, Jul 10 06:16:37 volumio volumio[814]: code: 'ETIMEDOUT', Jul 10 06:16:37 volumio volumio[814]: syscall: 'connect', Jul 10 06:16:37 volumio volumio[814]: address: '130.211.19.189', Jul 10 06:16:37 volumio volumio[814]: port: 80 Jul 10 06:16:37 volumio volumio[814]: } Jul 10 06:16:37 volumio volumio[814]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 10 06:16:38 volumio sudo[1990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-10 06:15 Jul 10 06:16:38 volumio sudo[1990]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"