-- Logs begin at Tue 2024-10-29 19:27:08 CET, end at Tue 2024-10-29 20:59:00 CET. -- Oct 29 20:58:03 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 20:58:03 volumio volumio[925]: info: Received Get System Info Oct 29 20:58:03 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 29 20:58:03 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 29 20:58:03 volumio volumio[925]: info: Discovery: Getting this device information Oct 29 20:58:03 volumio volumio[925]: info: CoreCommandRouter::volumioGetState Oct 29 20:58:03 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 29 20:58:07 volumio volumio[925]: info: CALLMETHOD: system_hardware rotaryencoder2 updateEncoder [object Object] Oct 29 20:58:07 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: rotaryencoder2 , updateEncoder Oct 29 20:58:07 volumio volumio[925]: error: [ROTARYENCODER2] detachListener: could not kill handler process [object Object] Oct 29 20:58:07 volumio sudo[6066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:07 volumio sudo[6066]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:07 volumio sudo[6066]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:07 volumio sudo[6069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Oct 29 20:58:07 volumio sudo[6069]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:08 volumio sudo[6069]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:08 volumio sudo[6080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:08 volumio sudo[6080]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:08 volumio sudo[6080]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:08 volumio sudo[6083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=27 pin_b=22 relative_axis=true steps-per-period=2 Oct 29 20:58:08 volumio sudo[6083]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:08 volumio kernel: rotary-encoder rotary@1b: gray Oct 29 20:58:08 volumio kernel: input: rotary@1b as /devices/platform/rotary@1b/input/input9 Oct 29 20:58:08 volumio sudo[6083]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:08 volumio systemd-udevd[6075]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::volumioStop Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::stop Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::stPlaybackTimer Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::updateTrackBlock Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrackBlock Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::serviceStop Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::serviceStop Oct 29 20:58:11 volumio volumio[925]: info: [1730231891310] ControllerWebradio::stop Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand stop Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:11 volumio volumio[925]: info: Oct 29 20:58:11 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand stop took 9 milliseconds Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand status took 1 milliseconds Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:11 volumio volumio[925]: info: Oct 29 20:58:11 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:11 volumio volumio[925]: info: Oct 29 20:58:11 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand status took 3 milliseconds Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand status took 2 milliseconds Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:11 volumio volumio[925]: info: ------------------------------ 15ms Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 29 20:58:11 volumio volumio[925]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:11 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:11 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:11 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:11 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:11 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:11 volumio volumio[925]: info: ------------------------------ 22ms Oct 29 20:58:11 volumio volumio[925]: info: ------------------------------ 21ms Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:11 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:14 volumio volumio[925]: info: CoreCommandRouter::volumioPlay Oct 29 20:58:14 volumio volumio[925]: info: CoreStateMachine::play index undefined Oct 29 20:58:14 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 29 20:58:14 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:14 volumio volumio[925]: info: CoreStateMachine::startPlaybackTimer Oct 29 20:58:14 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:14 volumio volumio[925]: info: [1730231894826] ControllerWebradio::clearAddPlayTrack Oct 29 20:58:14 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand stop Oct 29 20:58:14 volumio volumio[925]: info: sendMpdCommand stop took 1 milliseconds Oct 29 20:58:14 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand clear Oct 29 20:58:14 volumio volumio[925]: info: Oct 29 20:58:14 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:14 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:14 volumio volumio[925]: info: sendMpdCommand clear took 1 milliseconds Oct 29 20:58:14 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand load "http://www.katolikusradio.hu:9000/live_hi.mp3" Oct 29 20:58:14 volumio volumio[925]: info: Oct 29 20:58:14 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:14 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:14 volumio volumio[925]: info: Oct 29 20:58:14 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:14 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:14 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:14 volumio volumio[925]: info: ------------------------------ 4ms Oct 29 20:58:15 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:15 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand add "http://www.katolikusradio.hu:9000/live_hi.mp3" Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 607ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 607ms Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand add "http://www.katolikusradio.hu:9000/live_hi.mp3" took 2 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand play Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 8ms Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand play took 7 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 4ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 3ms Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 10 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 7 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 5 milliseconds Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 14 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 10 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 7 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand status took 5 milliseconds Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus stop Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:15 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:15 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 56ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 63ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 61ms Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 43 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 42 milliseconds Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: sendMpdCommand playlistinfo took 43 milliseconds Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:15 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:15 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:15 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:15 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:15 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:15 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:15 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 115ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 107ms Oct 29 20:58:15 volumio volumio[925]: info: ------------------------------ 106ms Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:15 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:15 volumio volumio[925]: info: Oct 29 20:58:15 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:15 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:15 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 133ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 131 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 132ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 131 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 31ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 30 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 29ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 29 milliseconds Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: info: Oct 29 20:58:16 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:16 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:16 volumio volumio[925]: info: Oct 29 20:58:16 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:16 volumio volumio[925]: info: Oct 29 20:58:16 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:16 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:16 volumio volumio[925]: info: Oct 29 20:58:16 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 24ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 34 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 33ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand status took 21 milliseconds Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":858,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":858,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 300ms Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 300ms Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 199ms Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 197ms Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 170 milliseconds Oct 29 20:58:16 volumio volumio[925]: info: sendMpdCommand playlistinfo took 170 milliseconds Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:16 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:16 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1110,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:16 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:16 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:16 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 240ms Oct 29 20:58:16 volumio volumio[925]: info: ------------------------------ 238ms Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:16 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::volumioStop Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::stop Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::stPlaybackTimer Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::updateTrackBlock Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrackBlock Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::serviceStop Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::serviceStop Oct 29 20:58:23 volumio volumio[925]: info: [1730231903380] ControllerWebradio::stop Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand stop Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:23 volumio volumio[925]: info: Oct 29 20:58:23 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand stop took 14 milliseconds Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:23 volumio volumio[925]: info: Oct 29 20:58:23 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:23 volumio volumio[925]: info: Oct 29 20:58:23 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand status took 10 milliseconds Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand status took 7 milliseconds Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand status took 4 milliseconds Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 29 20:58:23 volumio volumio[925]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:23 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:23 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:23 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:23 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:23 volumio volumio[925]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 29 20:58:23 volumio volumio[925]: info: ------------------------------ 45ms Oct 29 20:58:23 volumio volumio[925]: info: ------------------------------ 40ms Oct 29 20:58:23 volumio volumio[925]: info: ------------------------------ 38ms Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] CurState: stop PrevState: play Oct 29 20:58:23 volumio volumio[925]: info: [ASDebug] InitTimeout - Amp off in: 7200 ms Oct 29 20:58:28 volumio volumio[925]: info: CALLMETHOD: system_hardware rotaryencoder2 updateEncoder [object Object] Oct 29 20:58:28 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: rotaryencoder2 , updateEncoder Oct 29 20:58:28 volumio sudo[6138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:28 volumio sudo[6138]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:28 volumio sudo[6138]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:28 volumio sudo[6141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Oct 29 20:58:28 volumio sudo[6141]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:28 volumio kernel: OF: ERROR: memory leak, expected refcount 1 instead of 2, of_node_get()/of_node_put() unbalanced - destroy cset entry: attach overlay node /rotary@1b Oct 29 20:58:28 volumio kernel: OF: ERROR: memory leak before free overlay changeset, /rotary@1b Oct 29 20:58:28 volumio sudo[6141]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:28 volumio sudo[6153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:28 volumio sudo[6153]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:28 volumio sudo[6153]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:28 volumio sudo[6156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=27 pin_b=22 relative_axis=true steps-per-period=2 Oct 29 20:58:28 volumio sudo[6156]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:28 volumio kernel: rotary-encoder rotary@1b: gray Oct 29 20:58:28 volumio kernel: input: rotary@1b as /devices/platform/rotary@1b/input/input10 Oct 29 20:58:28 volumio sudo[6156]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:28 volumio systemd-udevd[6146]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 29 20:58:30 volumio volumio[925]: info: [ASDebug] Togle GPIO: OFF Oct 29 20:58:32 volumio volumio[925]: info: CoreCommandRouter::volumioPlay Oct 29 20:58:32 volumio volumio[925]: info: CoreStateMachine::play index undefined Oct 29 20:58:32 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 29 20:58:32 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:32 volumio volumio[925]: info: CoreStateMachine::startPlaybackTimer Oct 29 20:58:32 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:32 volumio volumio[925]: info: [1730231912960] ControllerWebradio::clearAddPlayTrack Oct 29 20:58:32 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand stop Oct 29 20:58:32 volumio volumio[925]: info: sendMpdCommand stop took 1 milliseconds Oct 29 20:58:32 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand clear Oct 29 20:58:32 volumio volumio[925]: info: sendMpdCommand clear took 1 milliseconds Oct 29 20:58:32 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand load "http://www.katolikusradio.hu:9000/live_hi.mp3" Oct 29 20:58:32 volumio volumio[925]: info: Oct 29 20:58:32 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:32 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:32 volumio volumio[925]: info: Oct 29 20:58:32 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:32 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:32 volumio volumio[925]: info: Oct 29 20:58:32 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:32 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand add "http://www.katolikusradio.hu:9000/live_hi.mp3" Oct 29 20:58:33 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:33 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:33 volumio volumio[925]: error: updateQueue error: null Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 339ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 338ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 336ms Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand add "http://www.katolikusradio.hu:9000/live_hi.mp3" took 7 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand play Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 17ms Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand play took 10 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 11ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 8ms Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 20 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 15 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 11 milliseconds Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 35 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 27 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 24 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 18 milliseconds Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus stop Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live_hi.mp3","artist":null,"album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 111ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 123ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 119ms Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces system playlist update Oct 29 20:58:33 volumio volumio[925]: info: Ignoring MPD Status Update Oct 29 20:58:33 volumio volumio[925]: info: Oct 29 20:58:33 volumio volumio[925]: ---------------------------- MPD announces state update: player Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::getState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand status Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 96 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 94ms Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 87 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 85 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 80 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 19ms Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 16 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 14ms Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand status took 11 milliseconds Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseState Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":862,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 197ms Oct 29 20:58:33 volumio volumio[925]: info: ------------------------------ 176ms Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: stop Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] Togle GPIO: ON Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 100 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 99 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 96 milliseconds Oct 29 20:58:33 volumio volumio[925]: info: sendMpdCommand playlistinfo took 96 milliseconds Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: verbose: ControllerMpd::parseTrackInfo Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":862,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":862,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":862,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: ControllerMpd::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::servicePushState Oct 29 20:58:33 volumio volumio[925]: info: CorePlayQueue::getTrack 0 Oct 29 20:58:33 volumio volumio[925]: verbose: STATE SERVICE {"status":"play","position":0,"seek":862,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Now Playing info goes here","artist":"Magyar Katolikus Radio elo adas","album":null,"uri":"http://www.katolikusradio.hu:9000/live_hi.mp3","trackType":"mp3"} Oct 29 20:58:33 volumio volumio[925]: verbose: CURRENT POSITION 0 Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState stateService play Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::syncState currentStatus play Oct 29 20:58:33 volumio volumio[925]: info: Received an update from plugin. extracting info from payload Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:33 volumio volumio[925]: info: CoreStateMachine::pushState Oct 29 20:58:33 volumio volumio[925]: info: CoreCommandRouter::volumioPushState Oct 29 20:58:34 volumio volumio[925]: info: ------------------------------ 297ms Oct 29 20:58:34 volumio volumio[925]: info: ------------------------------ 291ms Oct 29 20:58:34 volumio volumio[925]: info: ------------------------------ 216ms Oct 29 20:58:34 volumio volumio[925]: info: ------------------------------ 211ms Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:34 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:44 volumio volumio[925]: info: CoreCommandRouter::volumioGetState Oct 29 20:58:46 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 29 20:58:46 volumio volumio[925]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 29 20:58:49 volumio volumio[925]: info: [ASDebug] Port: 13 Oct 29 20:58:49 volumio volumio[925]: info: [ASDebug] Inverted: false Oct 29 20:58:49 volumio volumio[925]: info: [ASDebug] Delay: 7200 Oct 29 20:58:52 volumio sudo[6261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:52 volumio sudo[6261]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:52 volumio sudo[6261]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:52 volumio sudo[6264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Oct 29 20:58:52 volumio sudo[6264]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:52 volumio sudo[6264]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:52 volumio sudo[6274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 29 20:58:52 volumio sudo[6274]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 20:58:52 volumio sudo[6274]: pam_unix(sudo:session): session closed for user root Oct 29 20:58:52 volumio volumio[925]: info: Disabling plugin rotaryencoder2 Oct 29 20:58:52 volumio volumio[925]: info: Done. Oct 29 20:58:55 volumio volumio[925]: info: Enabling plugin ampswitch Oct 29 20:58:55 volumio volumio[925]: info: Loading plugin "ampswitch"... Oct 29 20:58:55 volumio volumio[925]: info: Applying required configuration parameters for plugin ampswitch Oct 29 20:58:55 volumio volumio[925]: info: PLUGIN START: ampswitch Oct 29 20:58:55 volumio volumio[925]: info: Done. Oct 29 20:58:55 volumio volumio[925]: info: CoreCommandRouter::volumioGetState Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] CurState: play PrevState: play Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] Port: 13 Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] Inverted: false Oct 29 20:58:55 volumio volumio[925]: info: [ASDebug] Delay: 7200 Oct 29 20:58:59 volumio volumio[925]: info: [ASDebug] Port: 13 Oct 29 20:58:59 volumio volumio[925]: info: [ASDebug] Inverted: false Oct 29 20:58:59 volumio volumio[925]: info: [ASDebug] Delay: 7200 Oct 29 20:58:59 volumio volumio[925]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 20:58:59 volumio volumio[925]: Error: EBADF: bad file descriptor, close Oct 29 20:58:59 volumio volumio[925]: at Object.closeSync (fs.js:439:3) Oct 29 20:58:59 volumio volumio[925]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Oct 29 20:58:59 volumio volumio[925]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Oct 29 20:58:59 volumio volumio[925]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:234:19) Oct 29 20:58:59 volumio volumio[925]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:84:10) Oct 29 20:58:59 volumio volumio[925]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Oct 29 20:58:59 volumio volumio[925]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Oct 29 20:58:59 volumio volumio[925]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1537:29) Oct 29 20:58:59 volumio volumio[925]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1387:47) Oct 29 20:58:59 volumio volumio[925]: at Socket.emit (events.js:315:20) Oct 29 20:58:59 volumio volumio[925]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 29 20:58:59 volumio volumio[925]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Oct 29 20:58:59 volumio volumio[925]: errno: -9, Oct 29 20:58:59 volumio volumio[925]: syscall: 'close', Oct 29 20:58:59 volumio volumio[925]: code: 'EBADF' Oct 29 20:58:59 volumio volumio[925]: } Oct 29 20:58:59 volumio volumio[925]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 20:59:00 volumio sudo[6309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-29 20:58 Oct 29 20:59:00 volumio sudo[6309]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"