-- Logs begin at Tue 2023-03-28 01:54:07 CST, end at Thu 2024-10-10 11:21:39 CST. -- Oct 10 11:20:05 ft4385-6450 sshd[13283]: rexec line 6: Deprecated option UsePrivilegeSeparation Oct 10 11:20:05 ft4385-6450 sshd[13283]: rexec line 7: Deprecated option KeyRegenerationInterval Oct 10 11:20:05 ft4385-6450 sshd[13283]: rexec line 8: Deprecated option ServerKeyBits Oct 10 11:20:05 ft4385-6450 sshd[13283]: rexec line 14: Deprecated option RSAAuthentication Oct 10 11:20:05 ft4385-6450 sshd[13283]: rexec line 17: Deprecated option RhostsRSAAuthentication Oct 10 11:20:05 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:05 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:05 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:05 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:05 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:06 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 11 Oct 10 11:20:13 ft4385-6450 sshd[13283]: reprocess config line 14: Deprecated option RSAAuthentication Oct 10 11:20:13 ft4385-6450 sshd[13283]: reprocess config line 17: Deprecated option RhostsRSAAuthentication Oct 10 11:20:13 ft4385-6450 sshd[13283]: Accepted password for volumio from 192.168.23.173 port 57629 ssh2 Oct 10 11:20:13 ft4385-6450 sshd[13283]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Oct 10 11:20:13 ft4385-6450 sshd[13328]: rexec line 6: Deprecated option UsePrivilegeSeparation Oct 10 11:20:13 ft4385-6450 sshd[13328]: rexec line 7: Deprecated option KeyRegenerationInterval Oct 10 11:20:13 ft4385-6450 sshd[13328]: rexec line 8: Deprecated option ServerKeyBits Oct 10 11:20:13 ft4385-6450 sshd[13328]: rexec line 14: Deprecated option RSAAuthentication Oct 10 11:20:13 ft4385-6450 sshd[13328]: rexec line 17: Deprecated option RhostsRSAAuthentication Oct 10 11:20:13 ft4385-6450 systemd-logind[2163]: New session c9 of user volumio. Oct 10 11:20:13 ft4385-6450 systemd[1]: Started Session c9 of user volumio. Oct 10 11:20:14 ft4385-6450 sshd[13328]: reprocess config line 14: Deprecated option RSAAuthentication Oct 10 11:20:14 ft4385-6450 sshd[13328]: reprocess config line 17: Deprecated option RhostsRSAAuthentication Oct 10 11:20:14 ft4385-6450 sshd[13328]: Accepted password for volumio from 192.168.23.173 port 57641 ssh2 Oct 10 11:20:14 ft4385-6450 sshd[13328]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Oct 10 11:20:14 ft4385-6450 systemd-logind[2163]: New session c10 of user volumio. Oct 10 11:20:14 ft4385-6450 systemd[1]: Started Session c10 of user volumio. Oct 10 11:20:15 ft4385-6450 sshd[13340]: error: Failed to allocate internet-domain X11 display socket. Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 11 Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Prefetching next song Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Doing Prefetch in UPNP Oct 10 11:20:32 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.23.23:50002/m/MP3/2866.mp3" Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { Oct 10 11:20:32 ft4385-6450 volumio[5956]: name: 'add "http://192.168.23.23:50002/m/MP3/2866.mp3"', Oct 10 11:20:32 ft4385-6450 volumio[5956]: args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Oct 10 11:20:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: sendMpdCommand add "http://192.168.23.23:50002/m/MP3/2866.mp3" took 8 milliseconds Oct 10 11:20:32 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'consume 1', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Oct 10 11:20:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Oct 10 11:20:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Oct 10 11:20:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Oct 10 11:20:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: ------------------------------ 28ms Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: sendMpdCommand consume 1 took 26 milliseconds Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: ------------------------------ 23ms Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: ------------------------------ 20ms Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: ------------------------------ 15ms Oct 10 11:20:32 ft4385-6450 volumio[5956]: info: ------------------------------ 11ms Oct 10 11:20:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::startPlaybackTimer Oct 10 11:20:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 10 11:20:37 ft4385-6450 volumio[5956]: error: Could not retrieve plugin audio_interface multiroom Oct 10 11:20:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetVisibleSources Oct 10 11:20:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 10 11:20:37 ft4385-6450 volumio[5956]: info: Listing playlists Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 70ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 67 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 63ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 58 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 54ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 47 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 38ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 31 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 24ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 13 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 21 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":60788,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"10 - 499Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2859.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":60880,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"10 - 499Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2859.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":60880,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"10 - 499Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2859.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":60880,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"10 - 499Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2859.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":60880,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"10 - 499Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2859.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 197ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 189ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 180ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 165ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 149ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Oct 10 11:20:44 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 45ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 43 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 26ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 24 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 22ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 20 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 18ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 16 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 13ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 12 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":61,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:20:44 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus play Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: Received an update from plugin. extracting info from payload Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 167ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 149ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 145ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 142ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: ------------------------------ 137ms Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:44 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:20:45 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:20:51 ft4385-6450 sudo[13558]: volumio : TTY=pts/0 ; PWD=/mnt/NAS ; USER=root ; COMMAND=/usr/bin/cp demo /workdir/ Oct 10 11:20:51 ft4385-6450 sudo[13558]: pam_unix(sudo:session): session opened for user root by volumio(uid=0) Oct 10 11:20:54 ft4385-6450 sudo[13558]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:16 ft4385-6450 sudo[13637]: volumio : TTY=pts/0 ; PWD=/mnt/NAS ; USER=root ; COMMAND=/usr/bin/cp pic/800x480/ /workdir/ -rf Oct 10 11:21:16 ft4385-6450 sudo[13637]: pam_unix(sudo:session): session opened for user root by volumio(uid=0) Oct 10 11:21:16 ft4385-6450 sudo[13637]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:31 ft4385-6450 sudo[13785]: volumio : TTY=pts/0 ; PWD=/mnt/NAS ; USER=root ; COMMAND=/usr/sbin/service demo start Oct 10 11:21:31 ft4385-6450 sudo[13785]: pam_unix(sudo:session): session opened for user root by volumio(uid=0) Oct 10 11:21:31 ft4385-6450 systemd[1]: Configuration file /etc/systemd/system/volspotconnect2.service is marked executable. Please remove executable permission bits. Proceeding anyway. Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 13 Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Prefetching next song Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Doing Prefetch in UPNP Oct 10 11:21:32 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.23.23:50002/m/MP3/2882.mp3" Oct 10 11:21:32 ft4385-6450 volumio[5956]: sendCommand: Command { Oct 10 11:21:32 ft4385-6450 volumio[5956]: name: 'add "http://192.168.23.23:50002/m/MP3/2882.mp3"', Oct 10 11:21:32 ft4385-6450 volumio[5956]: args: [] } Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Oct 10 11:21:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: sendMpdCommand add "http://192.168.23.23:50002/m/MP3/2882.mp3" took 9 milliseconds Oct 10 11:21:32 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand consume 1 Oct 10 11:21:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:21:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'consume 1', args: [] } Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Oct 10 11:21:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:21:32 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:21:32 ft4385-6450 volumio[5956]: info: Oct 10 11:21:32 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:21:33 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: Oct 10 11:21:33 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:21:33 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: Oct 10 11:21:33 ft4385-6450 volumio[5956]: ---------------------------- MPD announces system playlist update Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: Ignoring MPD Status Update Oct 10 11:21:33 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [] } Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: ------------------------------ 40ms Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: sendMpdCommand consume 1 took 36 milliseconds Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: ------------------------------ 32ms Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: ------------------------------ 27ms Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: ------------------------------ 21ms Oct 10 11:21:33 ft4385-6450 volumio[5956]: info: ------------------------------ 15ms Oct 10 11:21:35 ft4385-6450 systemd[1]: Started Demo Service. Oct 10 11:21:35 ft4385-6450 sudo[13785]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:35 ft4385-6450 demo[13809]: opt = t Oct 10 11:21:35 ft4385-6450 demo[13809]: optarg = /dev/ttyAS2 Oct 10 11:21:35 ft4385-6450 demo[13809]: optind = 3 Oct 10 11:21:35 ft4385-6450 demo[13809]: argv[optind - 1] = /dev/ttyAS2 Oct 10 11:21:35 ft4385-6450 demo[13809]: tty driver /dev/ttyAS2 Oct 10 11:21:35 ft4385-6450 demo[13809]: gui_screen_size_type_check 800 480 0 Oct 10 11:21:35 ft4385-6450 demo[13809]: SCREEN_SIZE_800X480 Oct 10 11:21:35 ft4385-6450 socketio[2350]: socket disconnet Oct 10 11:21:35 ft4385-6450 socketio[2350]: IP is 127.0.0.1 Oct 10 11:21:35 ft4385-6450 socketio[2350]: Port is 50666 Oct 10 11:21:35 ft4385-6450 socketio[2350]: 13 Oct 10 11:21:35 ft4385-6450 socketio[2350]: command_len 507 Oct 10 11:21:35 ft4385-6450 socketio[2350]: pushSrctotal Oct 10 11:21:35 ft4385-6450 socketio[2350]: { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "total": 11, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "cur": 0, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "source": [{ Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 0, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Media Player" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 4, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Bluetooth" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 2, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "DAB" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 3, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "FM" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 1, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "CD" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 5, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "USB Audio" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 6, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Aux 1" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 6, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Aux 2" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 5, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Optical" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 5, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "Coaxial" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }, { Oct 10 11:21:35 ft4385-6450 socketio[2350]: "type": 0, Oct 10 11:21:35 ft4385-6450 socketio[2350]: "name": "HDMI ARC" Oct 10 11:21:35 ft4385-6450 socketio[2350]: }] Oct 10 11:21:35 ft4385-6450 socketio[2350]: } Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 31 Oct 10 11:21:36 ft4385-6450 socketio[2350]: pushSourceInfo Oct 10 11:21:36 ft4385-6450 socketio[2350]: { Oct 10 11:21:36 ft4385-6450 socketio[2350]: "source": 0 Oct 10 11:21:36 ft4385-6450 socketio[2350]: } Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 9 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getState Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 36 Oct 10 11:21:36 ft4385-6450 socketio[2350]: setDeviceName Oct 10 11:21:36 ft4385-6450 socketio[2350]: {"name":"FT4385-9f55"} Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 14 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getDeviceName Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 9 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getQueue Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 demo[13809]: Failed to open file for reading: No such file or directory Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: System name has changed, restarting Shairport Sync Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 14 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getDeviceName Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 17 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getSystemVersion Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 36 Oct 10 11:21:36 ft4385-6450 socketio[2350]: setDeviceName Oct 10 11:21:36 ft4385-6450 socketio[2350]: {"name":"FT4385-9f55"} Oct 10 11:21:36 ft4385-6450 socketio[2350]: command_len 14 Oct 10 11:21:36 ft4385-6450 socketio[2350]: getDeviceName Oct 10 11:21:36 ft4385-6450 socketio[2350]: Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 10 11:21:36 ft4385-6450 volumio[5956]: [SpotifyConnect2] Creating VLS config file Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 10 11:21:36 ft4385-6450 volumio[5956]: [SpotifyConnect2] <> or Mixer found, using softvol Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Stopping playback through UPNP Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Stopping service currently in playback since Volumio is in Consume mode Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioStop Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::stop Oct 10 11:21:36 ft4385-6450 volumio[5956]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Oct 10 11:21:36 ft4385-6450 volumio[5956]: !! !! Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 10 11:21:36 ft4385-6450 volumio[5956]: !! !! Oct 10 11:21:36 ft4385-6450 volumio[5956]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: UNSET VOLATILE Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::stPlaybackTimer Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::updateTrackBlock Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrackBlock Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::serviceStop Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::serviceStop Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: [1728530496579] ControllerUPNPBrowser::stop Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand stop Oct 10 11:21:36 ft4385-6450 volumio[5956]: /usr/bin/sudo /usr/bin/killall upmpdcli Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'stop', args: [] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::volumioGetQueue Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::getQueue Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getQueue Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Received Get System Version Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:36 ft4385-6450 sudo[13840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Oct 10 11:21:36 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand stop took 177 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Oct 10 11:21:36 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Oct 10 11:21:36 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:21:36 ft4385-6450 sudo[13840]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Oct 10 11:21:36 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: Oct 10 11:21:36 ft4385-6450 volumio[5956]: ---------------------------- MPD announces state update: player Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::getState Oct 10 11:21:36 ft4385-6450 demo[13837]: % Total % Received % Xferd Average Speed Time Time Time Current Oct 10 11:21:36 ft4385-6450 demo[13837]: Dload Upload Total Spent Left Speed Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand status Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'status', args: [] } Oct 10 11:21:36 ft4385-6450 sudo[13844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 102 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 87 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 77 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 60 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand status took 44 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:21:36 ft4385-6450 sudo[13840]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseState Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 10 11:21:36 ft4385-6450 sudo[13844]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: sendCommand: Command { name: 'playlistinfo', args: [ 0 ] } Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 53 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 49 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 50 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 45 milliseconds Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: sendMpdCommand playlistinfo took 44 milliseconds Oct 10 11:21:36 ft4385-6450 sudo[13844]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: verbose: ControllerMpd::parseTrackInfo Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:36 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: No code Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: No code Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: No code Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: No code Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ControllerMpd::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11 - 997Hz 0dB","artist":"A BEX","album":"TCD-785","uri":"http://192.168.23.23:50002/m/MP3/2866.mp3","trackType":"mp3"} Oct 10 11:21:37 ft4385-6450 volumio[5956]: verbose: CURRENT POSITION 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState stateService stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::syncState currentStatus stop Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: No code Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreStateMachine::pushState Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CorePlayQueue::getTrack 12 Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ------------------------------ 454ms Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ------------------------------ 436ms Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ------------------------------ 425ms Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ------------------------------ 408ms Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: ------------------------------ 397ms Oct 10 11:21:37 ft4385-6450 volumio[5956]: [SpotifyConnect2] Restarting Vollibrespot Daemon Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 socketio[2350]: socket send Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: Starting Shairport Sync Oct 10 11:21:37 ft4385-6450 sudo[13871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: Permissions for /etc/hosts set Oct 10 11:21:37 ft4385-6450 sudo[13871]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:37 ft4385-6450 sudo[13875]: volumio : unable to resolve host ft4385-6450 Oct 10 11:21:37 ft4385-6450 sudo[13875]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Oct 10 11:21:37 ft4385-6450 volumio[5956]: info: Hostname now is ft4385-9f55 Oct 10 11:21:37 ft4385-6450 systemd[1]: Stopping Volspotconnect2 Daemon... Oct 10 11:21:37 ft4385-6450 systemd[1]: volspotconnect2.service: Succeeded. Oct 10 11:21:37 ft4385-6450 systemd[1]: Stopped Volspotconnect2 Daemon. Oct 10 11:21:37 ft4385-6450 sudo[13875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 10 11:21:37 ft4385-6450 systemd[1]: Started Volspotconnect2 Daemon. Oct 10 11:21:37 ft4385-6450 sudo[13880]: volumio : unable to resolve host ft4385-6450 Oct 10 11:21:37 ft4385-6450 sudo[13880]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Oct 10 11:21:37 ft4385-6450 sudo[13871]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:37 ft4385-6450 sudo[13875]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:37 ft4385-6450 sudo[13886]: volumio : unable to resolve host ft4385-6450 Oct 10 11:21:37 ft4385-6450 sudo[13886]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Oct 10 11:21:37 ft4385-6450 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 10 11:21:37 ft4385-6450 sudo[13880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hostname ft4385-9f55 Oct 10 11:21:37 ft4385-6450 systemd[1]: shairport-sync.service: Succeeded. Oct 10 11:21:37 ft4385-6450 sudo[13886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /etc/avahi/services/ Oct 10 11:21:37 ft4385-6450 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 10 11:21:37 ft4385-6450 volumio[5956]: [SpotifyConnect2] Vollibrespot Daemon service restarted! Oct 10 11:21:37 ft4385-6450 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 10 11:21:37 ft4385-6450 sudo[13880]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:37 ft4385-6450 sudo[13875]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:37 ft4385-6450 sudo[13886]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 10 11:21:37 ft4385-9f55 systemd-resolved[2140]: System hostname changed to 'ft4385-9f55'. Oct 10 11:21:37 ft4385-9f55 sudo[13880]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:37 ft4385-9f55 sudo[13886]: pam_unix(sudo:session): session closed for user root Oct 10 11:21:37 ft4385-9f55 volumio[5956]: info: New hostname set Oct 10 11:21:37 ft4385-9f55 volumio[5956]: info: Shairport-Sync Started Oct 10 11:21:38 ft4385-9f55 volumio[5956]: info: Permissions for /etc/avahi/services/volumio.service Oct 10 11:21:38 ft4385-9f55 volumio[5956]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 11:21:38 ft4385-9f55 volumio[5956]: ReferenceError: path is not defined Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at /volumio/app/plugins/system_controller/system/index.js:335:51 Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at ChildProcess.exithandler (child_process.js:285:7) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at ChildProcess.emit (events.js:198:13) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at maybeClose (internal/child_process.js:982:16) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at Socket.stream.socket.on (internal/child_process.js:389:11) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at Socket.emit (events.js:198:13) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: at Pipe._handle.close (net.js:607:12) Oct 10 11:21:38 ft4385-9f55 volumio[5956]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 10 11:21:39 ft4385-9f55 systemd[1]: upmpdcli.service: Succeeded. Oct 10 11:21:39 ft4385-9f55 sudo[13934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-10 11:20 Oct 10 11:21:39 ft4385-9f55 sudo[13934]: pam_unix(sudo:session): session opened for user root by (uid=0) NAME="Ubuntu" VERSION="20.04.5 LTS (Focal Fossa)" ID=ubuntu ID_LIKE=debian PRETTY_NAME="Ubuntu 20.04.5 LTS" VERSION_ID="20.04" HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" VERSION_CODENAME=focal UBUNTU_CODENAME=focal VOLUMIO_BUILD_VERSION="" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_BE_VERSION="3e944f35d34b575025d16b976b4cb4d9aed53b66" VOLUMIO_ARCH="armv7" VOLUMIO_VERSION=2024.09.20.96 VOLUMIO_BUILD_DATE=2024-09-20 16:24:53 VOLUMIO_VARIANT=volumio VOLUMIO_HARDWARE=Generic DT based system