-- Logs begin at Thu 2019-02-14 13:11:59 MSK, end at Fri 2025-05-30 13:39:34 MSK. -- May 30 13:38:00 volumio volumio[861]: info: MyVolumio status changed May 30 13:38:00 volumio volumio[861]: info: Streaming services startup May 30 13:38:00 volumio volumio[861]: info: Starting Streaming Daemon May 30 13:38:00 volumio volumio[861]: info: Removing browser output: myVolumio user plan is not superstar May 30 13:38:01 volumio volumio[861]: info: Removing audio output: May 30 13:38:01 volumio volumio[861]: info: Stoppping Tunnel 1 May 30 13:38:01 volumio volumio[861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 May 30 13:38:01 volumio sudo[1785]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 30 13:38:01 volumio sudo[1783]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 30 13:38:01 volumio sudo[1785]: pam_unix(sudo:session): session opened for user root by (uid=0) May 30 13:38:01 volumio sudo[1783]: pam_unix(sudo:session): session opened for user root by (uid=0) May 30 13:38:01 volumio sudo[1783]: pam_unix(sudo:session): session closed for user root May 30 13:38:01 volumio volumio[861]: error: Cannot start Volumio Streaming Daemon May 30 13:38:01 volumio volumio[861]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 30 13:38:01 volumio volumio[861]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 30 13:38:02 volumio sudo[1785]: pam_unix(sudo:session): session closed for user root May 30 13:38:02 volumio volumio[861]: info: Remote SSH Stopped May 30 13:38:02 volumio ntpd[693]: Soliciting pool server 195.54.177.84 May 30 13:38:02 volumio ntpd[693]: Soliciting pool server 151.0.2.53 May 30 13:38:03 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 13:38:03 volumio ntpd[693]: Soliciting pool server 85.193.65.152 May 30 13:38:03 volumio ntpd[693]: Soliciting pool server 178.217.98.201 May 30 13:38:03 volumio ntpd[693]: Soliciting pool server 193.106.93.116 May 30 13:38:03 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 30 13:38:04 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 13:38:04 volumio ntpd[693]: Soliciting pool server 185.211.244.47 May 30 13:38:04 volumio ntpd[693]: Soliciting pool server 92.255.126.1 May 30 13:38:04 volumio ntpd[693]: Soliciting pool server 176.123.165.98 May 30 13:38:04 volumio volumio[861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 30 13:38:04 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:04 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:04 volumio volumio[861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 30 13:38:05 volumio ntpd[693]: Soliciting pool server 91.201.254.110 May 30 13:38:05 volumio ntpd[693]: Soliciting pool server 89.109.251.22 May 30 13:38:05 volumio ntpd[693]: Soliciting pool server 91.201.254.110 May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::volumioGetVisibleSources May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:05 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 30 13:38:05 volumio volumio[861]: info: Received Get System Info May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 13:38:05 volumio volumio[861]: info: Discovery: Getting this device information May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:05 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 13:38:05 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:05 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:05 volumio volumio[861]: info: Listing playlists May 30 13:38:06 volumio ntpd[693]: Soliciting pool server 92.241.18.100 May 30 13:38:06 volumio ntpd[693]: Soliciting pool server 217.28.222.15 May 30 13:38:06 volumio ntpd[693]: Soliciting pool server 213.108.170.26 May 30 13:38:06 volumio volumio[861]: info: Setting Geolocation for MyVolumio to eu2 May 30 13:38:06 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:06 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:06 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:07 volumio ntpd[693]: Soliciting pool server 176.124.213.143 May 30 13:38:07 volumio ntpd[693]: Soliciting pool server 2a00:1390:5:722b:1337:c0de:4:11 May 30 13:38:07 volumio ntpd[693]: Soliciting pool server 151.0.2.54 May 30 13:38:07 volumio volumio[861]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 30 13:38:07 volumio volumio[861]: info: Updating MyVolumio device info May 30 13:38:07 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:07 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:07 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:07 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 13:38:08 volumio volumio[861]: info: Received Get System Info May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 13:38:08 volumio volumio[861]: info: Discovery: Getting this device information May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:08 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 13:38:08 volumio ntpd[693]: Soliciting pool server 89.169.135.41 May 30 13:38:08 volumio ntpd[693]: Soliciting pool server 81.163.27.123 May 30 13:38:08 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 30 13:38:09 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 13:38:10 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 13:38:10 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 30 13:38:10 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 30 13:38:10 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 30 13:38:10 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40912.3e3fe51e does not match aorg 0000000000.00000000 from server@193.106.93.116 xmt 0xebe40913.19554c84 May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40912.3e3005ec does not match aorg 0000000000.00000000 from server@92.241.18.100 xmt 0xebe40913.1952c098 May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40912.3e39b69b does not match aorg 0000000000.00000000 from server@91.201.254.110 xmt 0xebe40913.19feed6a May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.40586071 does not match aorg 0000000000.00000000 from server@213.108.170.26 xmt 0xebe40914.1a61cffe May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.405b328d does not match aorg 0000000000.00000000 from server@85.193.65.152 xmt 0xebe40914.1a73a365 May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.4059c24b does not match aorg 0000000000.00000000 from server@185.211.244.47 xmt 0xebe40914.1b849cff May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.404945e5 does not match aorg 0000000000.00000000 from server@81.163.27.123 xmt 0xebe40914.1ab9f559 May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.4052bf52 does not match aorg 0000000000.00000000 from server@89.169.135.41 xmt 0xebe40914.1afcaa74 May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.40567c4d does not match aorg 0000000000.00000000 from server@217.28.222.15 xmt 0xebe40914.1ad34b8e May 30 13:38:12 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40913.4054d476 does not match aorg 0000000000.00000000 from server@151.0.2.54 xmt 0xebe40914.1da9a7d7 May 30 13:38:12 volumio volumio[861]: info: CoreCommandRouter::volumioGetBrowseSources May 30 13:38:12 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 13:38:12 volumio volumio[861]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 30 13:38:12 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 30 13:38:13 volumio volumio[861]: info: MYVOLUMIO: Adding device May 30 13:38:13 volumio volumio[861]: info: MYVOLUMIO: Evaluating Server May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 13:38:13 volumio volumio[861]: info: Received Get System Info May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 13:38:13 volumio volumio[861]: info: Discovery: Getting this device information May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:13 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 13:38:13 volumio volumio[861]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 30 13:38:13 volumio volumio[861]: info: Completed starting MyVolumio Plugin May 30 13:38:13 volumio volumio[861]: [Metrics] CommandRouter: 63s 746.75ms May 30 13:38:13 volumio volumio[861]: info: CoreCommandRouter::volumiosetStartupVolume May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::Close All Modals sent May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::Close All Modals sent May 30 13:38:14 volumio volumio[861]: info: Setting Geolocation for MyVolumio to eu6 May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:14 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 30 13:38:15 volumio volumio[861]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 30 13:38:15 volumio volumio[861]: info: Updating MyVolumio device info May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 13:38:15 volumio volumio[861]: info: Received Get System Info May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 13:38:15 volumio volumio[861]: info: Discovery: Getting this device information May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:15 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:15 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 13:38:17 volumio volumio[861]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 30 13:38:21 volumio volumio[861]: info: BOOT COMPLETED May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 13:38:25 volumio volumio[861]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 30 13:38:25 volumio volumio[861]: info: Received Get System Version May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 13:38:25 volumio volumio[861]: info: Received Get System Info May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 13:38:25 volumio volumio[861]: info: Discovery: Getting this device information May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::volumioGetState May 30 13:38:25 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:25 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 13:38:48 volumio volumio[861]: info: CoreCommandRouter::volumioPlay May 30 13:38:48 volumio volumio[861]: info: CoreStateMachine::play index undefined May 30 13:38:48 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 13:38:48 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:48 volumio volumio[861]: info: CoreStateMachine::startPlaybackTimer May 30 13:38:48 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:48 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand stop May 30 13:38:48 volumio volumio[861]: info: sendMpdCommand stop took 36 milliseconds May 30 13:38:48 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand clear May 30 13:38:48 volumio volumio[861]: info: sendMpdCommand clear took 2 milliseconds May 30 13:38:48 volumio volumio[861]: info: May 30 13:38:48 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:48 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:48 volumio volumio[861]: info: May 30 13:38:48 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:48 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:48 volumio volumio[861]: info: May 30 13:38:48 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:48 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:48 volumio volumio[861]: error: updateQueue error: null May 30 13:38:48 volumio volumio[861]: error: updateQueue error: null May 30 13:38:48 volumio volumio[861]: error: updateQueue error: null May 30 13:38:48 volumio volumio[861]: info: ------------------------------ 17ms May 30 13:38:48 volumio volumio[861]: info: ------------------------------ 10ms May 30 13:38:48 volumio volumio[861]: info: ------------------------------ 8ms May 30 13:38:48 volumio volumio[861]: error: Upnp client error: Error: This socket has been ended by the other party May 30 13:38:50 volumio volumio[861]: info: CoreCommandRouter::volumioPlay May 30 13:38:50 volumio volumio[861]: info: CoreStateMachine::play index undefined May 30 13:38:50 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 13:38:50 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:50 volumio volumio[861]: info: CoreStateMachine::startPlaybackTimer May 30 13:38:50 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:38:50 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand stop May 30 13:38:50 volumio volumio[861]: info: sendMpdCommand stop took 2 milliseconds May 30 13:38:50 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand clear May 30 13:38:50 volumio volumio[861]: info: May 30 13:38:50 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:50 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:50 volumio volumio[861]: info: sendMpdCommand clear took 2 milliseconds May 30 13:38:50 volumio volumio[861]: info: May 30 13:38:50 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:50 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:50 volumio volumio[861]: info: May 30 13:38:50 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:50 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:50 volumio volumio[861]: error: updateQueue error: null May 30 13:38:50 volumio volumio[861]: error: updateQueue error: null May 30 13:38:50 volumio volumio[861]: error: updateQueue error: null May 30 13:38:50 volumio volumio[861]: info: ------------------------------ 20ms May 30 13:38:50 volumio volumio[861]: info: ------------------------------ 7ms May 30 13:38:50 volumio volumio[861]: info: ------------------------------ 6ms May 30 13:38:53 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3" May 30 13:38:53 volumio volumio[861]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3" took 53 milliseconds May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 30ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 27ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 25ms May 30 13:38:53 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 13:38:53 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand play May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 32ms May 30 13:38:53 volumio volumio[861]: info: sendMpdCommand play took 26 milliseconds May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 27ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 26ms May 30 13:38:53 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2309e07f355f046b126766b07b3c254514f9fe0f970f15ce32a06f82b86b1e3a%2Clid%3D1519%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3" May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: sendMpdCommand addid "http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D2309e07f355f046b126766b07b3c254514f9fe0f970f15ce32a06f82b86b1e3a%2Clid%3D1519%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3" took 5 milliseconds May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: verbose: MPD COMMAND [object Object] May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 14ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 8ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 7ms May 30 13:38:53 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 13:38:53 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand play May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: May 30 13:38:53 volumio volumio[861]: ---------------------------- MPD announces system playlist update May 30 13:38:53 volumio volumio[861]: info: Ignoring MPD Status Update May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 14ms May 30 13:38:53 volumio volumio[861]: info: sendMpdCommand play took 9 milliseconds May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 7ms May 30 13:38:53 volumio volumio[861]: info: ------------------------------ 6ms May 30 13:39:11 volumio kernel: usb 1-1: USB disconnect, device number 2 May 30 13:39:11 volumio thd[536]: Error reading device '/dev/input/event1' May 30 13:39:11 volumio thd[536]: Error reading device '/dev/input/event2' May 30 13:39:11 volumio kernel: Indeed it is in host mode hprt0 = 00021501 May 30 13:39:12 volumio kernel: usb 1-1: new full-speed USB device number 3 using dwc_otg May 30 13:39:12 volumio kernel: Indeed it is in host mode hprt0 = 00021501 May 30 13:39:12 volumio volumio[861]: info: No valid Plugin REST Endpoint May 30 13:39:12 volumio kernel: usb 1-1: New USB device found, idVendor=1915, idProduct=1001, bcdDevice= 2.21 May 30 13:39:12 volumio kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 30 13:39:12 volumio kernel: usb 1-1: Product: BLE Remote May 30 13:39:12 volumio kernel: usb 1-1: Manufacturer: ZhenYe Tech May 30 13:39:12 volumio kernel: input: ZhenYe Tech BLE Remote as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0002/input/input3 May 30 13:39:12 volumio kernel: input: ZhenYe Tech BLE Remote Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0002/input/input4 May 30 13:39:12 volumio kernel: input: ZhenYe Tech BLE Remote Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0002/input/input5 May 30 13:39:12 volumio kernel: hid-generic 0003:1915:1001.0002: input,hidraw0: USB HID v2.01 Keyboard [ZhenYe Tech BLE Remote] on usb-3f980000.usb-1/input2 May 30 13:39:12 volumio volumio[861]: info: No valid Plugin REST Endpoint May 30 13:39:13 volumio systemd-udevd[2017]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:13 volumio systemd-udevd[2013]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:13 volumio systemd-udevd[2015]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:13 volumio systemd-udevd[2030]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:13 volumio systemd-logind[513]: Watching system buttons on /dev/input/event1 (ZhenYe Tech BLE Remote Keyboard) May 30 13:39:17 volumio kernel: usb 1-1: USB disconnect, device number 3 May 30 13:39:17 volumio volumio[861]: info: No valid Plugin REST Endpoint May 30 13:39:17 volumio kernel: Indeed it is in host mode hprt0 = 00021501 May 30 13:39:18 volumio kernel: usb 1-1: new full-speed USB device number 4 using dwc_otg May 30 13:39:18 volumio kernel: Indeed it is in host mode hprt0 = 00021501 May 30 13:39:18 volumio kernel: usb 1-1: New USB device found, idVendor=1915, idProduct=1001, bcdDevice= 2.21 May 30 13:39:18 volumio kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 May 30 13:39:18 volumio kernel: usb 1-1: Product: BLE Remote May 30 13:39:18 volumio kernel: usb 1-1: Manufacturer: ZhenYe Tech May 30 13:39:18 volumio kernel: input: ZhenYe Tech BLE Remote as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0003/input/input6 May 30 13:39:18 volumio kernel: input: ZhenYe Tech BLE Remote Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0003/input/input7 May 30 13:39:18 volumio kernel: input: ZhenYe Tech BLE Remote Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1:1.2/0003:1915:1001.0003/input/input8 May 30 13:39:18 volumio kernel: hid-generic 0003:1915:1001.0003: input,hidraw0: USB HID v2.01 Keyboard [ZhenYe Tech BLE Remote] on usb-3f980000.usb-1/input2 May 30 13:39:18 volumio volumio[861]: info: No valid Plugin REST Endpoint May 30 13:39:18 volumio systemd-udevd[2017]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:18 volumio systemd-udevd[2016]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:19 volumio systemd-udevd[2030]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:19 volumio systemd-logind[513]: Watching system buttons on /dev/input/event1 (ZhenYe Tech BLE Remote Keyboard) May 30 13:39:19 volumio systemd-udevd[2015]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 48 milliseconds May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 68 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 59 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus stop May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 144ms May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: May 30 13:39:23 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 78 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 75 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 74 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 9 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand status took 7 milliseconds May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":285,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:23 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":376,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:23 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 253ms May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 249ms May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 112 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 110 milliseconds May 30 13:39:23 volumio volumio[861]: info: sendMpdCommand playlistinfo took 110 milliseconds May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":932,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:23 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":932,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:23 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:23 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:23 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1034,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:23 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:23 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:23 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 384ms May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 315ms May 30 13:39:23 volumio volumio[861]: info: ------------------------------ 314ms May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioPause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::stPlaybackTimer May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::servicePause May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::servicePause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::pause May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand pause May 30 13:39:24 volumio volumio[861]: info: May 30 13:39:24 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand pause took 10 milliseconds May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:24 volumio volumio[861]: info: May 30 13:39:24 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:24 volumio volumio[861]: info: May 30 13:39:24 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand status took 48 milliseconds May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand status took 46 milliseconds May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand status took 44 milliseconds May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 13:39:24 volumio volumio[861]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:24 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:24 volumio volumio[861]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:24 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState stateService pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::stPlaybackTimer May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:24 volumio volumio[861]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:24 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState stateService pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::stPlaybackTimer May 30 13:39:24 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:24 volumio volumio[861]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:24 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState stateService pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus pause May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::stPlaybackTimer May 30 13:39:24 volumio volumio[861]: info: ------------------------------ 111ms May 30 13:39:24 volumio volumio[861]: info: ------------------------------ 109ms May 30 13:39:24 volumio volumio[861]: info: ------------------------------ 111ms May 30 13:39:24 volumio volumio[861]: info: touch_display: Setting screensaver timeout to 0 seconds. May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:24 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:24 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:24 volumio volumio[861]: info: touch_display: Setting screensaver timeout to 0 seconds. May 30 13:39:24 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40957.132a5803 does not match aorg 0xebe4095b.132b644e from server@213.108.170.26 xmt 0xebe40957.1bab10ba May 30 13:39:25 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40957.1321fe0e does not match aorg 0xebe4095d.1321ad67 from server@89.169.135.41 xmt 0xebe40957.1c8132de May 30 13:39:27 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40958.1333bd17 does not match aorg 0xebe4095e.132c1ff8 from server@85.193.65.152 xmt 0xebe40958.21e7d998 May 30 13:39:27 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40958.13228f3e does not match aorg 0xebe4095e.13223e20 from server@81.163.27.123 xmt 0xebe40958.22f35e31 May 30 13:39:27 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40958.132a8054 does not match aorg 0xebe4095e.132907c5 from server@151.0.2.54 xmt 0xebe40958.25e74c89 May 30 13:39:27 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40959.1333effd does not match aorg 0xebe4095f.132cbae8 from server@213.108.170.26 xmt 0xebe40959.1da2e7f6 May 30 13:39:27 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40959.1324e381 does not match aorg 0xebe4095f.1322a308 from server@89.169.135.41 xmt 0xebe40959.1e6a0b8c May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPlay May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::play index undefined May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::startPlaybackTimer May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::resume May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand play May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand play took 26 milliseconds May 30 13:39:27 volumio volumio[861]: info: May 30 13:39:27 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:27 volumio volumio[861]: info: May 30 13:39:27 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:27 volumio volumio[861]: info: May 30 13:39:27 volumio volumio[861]: ---------------------------- MPD announces state update: player May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::getState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand status May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand status took 8 milliseconds May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand status took 5 milliseconds May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand status took 3 milliseconds May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::parseState May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 13:39:27 volumio volumio[861]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 13:39:27 volumio volumio[861]: verbose: ControllerMpd::parseTrackInfo May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:27 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:27 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus pause May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:27 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:27 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:27 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:27 volumio volumio[861]: info: ControllerMpd::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::servicePushState May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getTrack 0 May 30 13:39:27 volumio volumio[861]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1549,"duration":241,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Whiskey","artist":"Tejon Street Corner Thieves","album":"Thick As Thieves","uri":"http://localhost:6601/?codec=mp3&url=https%3A%2F%2Fstrm-m9-161.strm.yandex.net%2Fmusic-v2%2Fraw%2Fysign1%3D0c8d2809d46fd40d4140da2e794f4d07caf7f1162950d5a8e6cbeeb519dd9720%2Clid%3D1524%2Cpfx%2Csecret_version%3Dver-1%2Csfx%2Csource%3Dmds%2Cts%3D684775ab%2F37719%2F10408%2F828abefd.137047442.10.90906320%2F320.mp3&ext=.mp3","trackType":"mp3"} May 30 13:39:27 volumio volumio[861]: verbose: CURRENT POSITION 0 May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState stateService play May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::syncState currentStatus play May 30 13:39:27 volumio volumio[861]: info: Received an update from plugin. extracting info from payload May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::pushState May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioPushState May 30 13:39:27 volumio volumio[861]: info: ------------------------------ 93ms May 30 13:39:27 volumio volumio[861]: info: ------------------------------ 92ms May 30 13:39:27 volumio volumio[861]: info: ------------------------------ 91ms May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:27 volumio volumio[861]: info: CoreCommandRouter::volumioGetQueue May 30 13:39:27 volumio volumio[861]: info: CoreStateMachine::getQueue May 30 13:39:27 volumio volumio[861]: info: CorePlayQueue::getQueue May 30 13:39:28 volumio volumio[861]: info: touch_display: Setting screensaver timeout to 0 seconds. May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095a.1330f669 does not match aorg 0xebe4095e.132c1ff8 from server@85.193.65.152 xmt 0xebe4095a.2b70de8f May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095a.132591cb does not match aorg 0xebe4095e.13223e20 from server@81.163.27.123 xmt 0xebe4095a.2ca9bcfd May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095a.132d9865 does not match aorg 0xebe4095e.132907c5 from server@151.0.2.54 xmt 0xebe4095a.2f9c5233 May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095b.132b644e does not match aorg 0xebe4095f.132cbae8 from server@213.108.170.26 xmt 0xebe4095b.1c685553 May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095b.1321d8c2 does not match aorg 0xebe4095f.1322a308 from server@89.169.135.41 xmt 0xebe4095b.1d2ee6dc May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095c.144b8f26 does not match aorg 0xebe4095e.132c1ff8 from server@85.193.65.152 xmt 0xebe4095c.24dfdef8 May 30 13:39:28 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095c.142e35a0 does not match aorg 0xebe40960.132e0842 from server@151.0.2.54 xmt 0xebe4095c.279e079e May 30 13:39:29 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095d.132849f6 does not match aorg 0xebe4095f.132cbae8 from server@213.108.170.26 xmt 0xebe4095d.1dc4da90 May 30 13:39:29 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095d.1321ad67 does not match aorg 0xebe4095f.1322a308 from server@89.169.135.41 xmt 0xebe4095d.1e9492a0 May 30 13:39:30 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe4095e.132907c5 does not match aorg 0xebe40960.132e0842 from server@151.0.2.54 xmt 0xebe4095e.246bf2c5 May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40960.133440ee does not match aorg 0xebe40964.132a7c4f from server@193.106.93.116 xmt 0xebe40960.3194c626 May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40960.132fe51d does not match aorg 0xebe40964.132278bc from server@92.241.18.100 xmt 0xebe40960.3244efce May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40960.13316f9d does not match aorg 0xebe40964.1328d808 from server@91.201.254.110 xmt 0xebe40960.32d122cc May 30 13:39:32 volumio volumio[861]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40962.1322ddd5 does not match aorg 0xebe40964.132278bc from server@92.241.18.100 xmt 0xebe40962.1ccc73be May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40962.132afa38 does not match aorg 0xebe40964.1328d808 from server@91.201.254.110 xmt 0xebe40962.1d60b902 May 30 13:39:32 volumio ntpd[693]: receive: Unexpected origin timestamp 0xebe40962.132e3ad2 does not match aorg 0xebe40964.132a7c4f from server@193.106.93.116 xmt 0xebe40962.1fc11ebc May 30 13:39:32 volumio volumio[861]: Error: read ECONNRESET May 30 13:39:32 volumio volumio[861]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { May 30 13:39:32 volumio volumio[861]: errno: -104, May 30 13:39:32 volumio volumio[861]: code: 'ECONNRESET', May 30 13:39:32 volumio volumio[861]: syscall: 'read' May 30 13:39:32 volumio volumio[861]: } May 30 13:39:32 volumio volumio[861]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 13:39:34 volumio sudo[2173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-30 13:38 May 30 13:39:34 volumio sudo[2173]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"