-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Mon 2025-10-27 11:44:53 CET. -- Oct 27 11:43:05 volumio2 go-librespot[26702]: time="2025-10-27T11:43:05+01:00" level=trace msg="received accesspoint ping" Oct 27 11:43:05 volumio2 go-librespot[26702]: time="2025-10-27T11:43:05+01:00" level=trace msg="received accesspoint pong ack" Oct 27 11:43:05 volumio2 go-librespot[26702]: time="2025-10-27T11:43:05+01:00" level=trace msg="sent dealer ping" Oct 27 11:43:05 volumio2 go-librespot[26702]: time="2025-10-27T11:43:05+01:00" level=trace msg="received dealer pong" Oct 27 11:43:34 volumio2 nmbd[777]: [2025/10/27 11:43:34.906058, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 27 11:43:34 volumio2 nmbd[777]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.178.50 for name WORKGROUP<1d>. Oct 27 11:43:34 volumio2 nmbd[777]: This response was from IP 192.168.178.20, reporting an IP address of 192.168.178.20. Oct 27 11:43:35 volumio2 go-librespot[26702]: time="2025-10-27T11:43:35+01:00" level=trace msg="sent dealer ping" Oct 27 11:43:35 volumio2 go-librespot[26702]: time="2025-10-27T11:43:35+01:00" level=trace msg="received dealer pong" Oct 27 11:44:01 volumio2 volumio[26398]: info: CALLMETHOD: system_hardware rotaryencoder2 updateEncoder [object Object] Oct 27 11:44:01 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: rotaryencoder2 , updateEncoder Oct 27 11:44:01 volumio2 sudo[27204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:01 volumio2 sudo[27204]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:01 volumio2 sudo[27204]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:01 volumio2 sudo[27207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 3 Oct 27 11:44:01 volumio2 sudo[27207]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:01 volumio2 sudo[27207]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:01 volumio2 sudo[27218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:01 volumio2 sudo[27218]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:01 volumio2 sudo[27218]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:01 volumio2 sudo[27221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 2 Oct 27 11:44:01 volumio2 sudo[27221]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:01 volumio2 sudo[27221]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:01 volumio2 sudo[27230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:01 volumio2 sudo[27230]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:01 volumio2 sudo[27230]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:02 volumio2 sudo[27233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 1 Oct 27 11:44:02 volumio2 sudo[27233]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:02 volumio2 sudo[27233]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:02 volumio2 sudo[27242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:02 volumio2 sudo[27242]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:02 volumio2 sudo[27242]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:02 volumio2 sudo[27245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Oct 27 11:44:02 volumio2 sudo[27245]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:02 volumio2 sudo[27245]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:02 volumio2 sudo[27254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=21 pin_b=20 relative_axis=true steps-per-period=1 Oct 27 11:44:02 volumio2 sudo[27254]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:02 volumio2 kernel: rotary-encoder rotary@15: gray Oct 27 11:44:02 volumio2 kernel: input: rotary@15 as /devices/platform/rotary@15/input/input37 Oct 27 11:44:02 volumio2 sudo[27254]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:02 volumio2 systemd-udevd[27212]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:02 volumio2 sudo[27268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=16 active_low=true gpio_pull=up keycode=20 Oct 27 11:44:02 volumio2 sudo[27268]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:02 volumio2 kernel: input: button@10 as /devices/platform/button@10/input/input38 Oct 27 11:44:02 volumio2 sudo[27268]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:03 volumio2 systemd-udevd[27212]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:03 volumio2 sudo[27281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=6 pin_b=13 relative_axis=true steps-per-period=1 Oct 27 11:44:03 volumio2 sudo[27281]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:03 volumio2 kernel: rotary-encoder rotary@6: gray Oct 27 11:44:03 volumio2 kernel: input: rotary@6 as /devices/platform/rotary@6/input/input39 Oct 27 11:44:03 volumio2 sudo[27281]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:03 volumio2 systemd-udevd[27212]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:03 volumio2 sudo[27295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=19 active_low=true gpio_pull=up keycode=20 Oct 27 11:44:03 volumio2 sudo[27295]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:03 volumio2 kernel: input: button@13 as /devices/platform/button@13/input/input40 Oct 27 11:44:03 volumio2 sudo[27295]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:03 volumio2 systemd-udevd[27212]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:03 volumio2 sudo[27308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:03 volumio2 sudo[27308]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:03 volumio2 sudo[27308]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:05 volumio2 go-librespot[26702]: time="2025-10-27T11:44:05+01:00" level=trace msg="sent dealer ping" Oct 27 11:44:05 volumio2 go-librespot[26702]: time="2025-10-27T11:44:05+01:00" level=trace msg="received dealer pong" Oct 27 11:44:20 volumio2 volumio[26398]: info: VolumeController::SetAlsaVolume+ Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:20 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:20 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: stop Oct 27 11:44:20 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Oct 27 11:44:20 volumio2 volumio[26398]: SPOTIFY: SPOTIFY VOLUME 50 Oct 27 11:44:20 volumio2 volumio[26398]: SPOTIFY: VOLUMIO VOLUME 55 Oct 27 11:44:20 volumio2 volumio[26398]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 27 11:44:20 volumio2 volumio[26398]: info: Setting Spotify Volume from Volumio: 55 Oct 27 11:44:20 volumio2 volumio[26398]: info: VolumeController::SetAlsaVolume+ Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:20 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:20 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:21 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: stop Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: SPOTIFY VOLUME 55 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: VOLUMIO VOLUME 60 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 27 11:44:21 volumio2 volumio[26398]: info: Setting Spotify Volume from Volumio: 60 Oct 27 11:44:21 volumio2 volumio[26398]: info: VolumeController::SetAlsaVolume+ Oct 27 11:44:21 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:21 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:21 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:21 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:21 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: stop Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: SPOTIFY VOLUME 60 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: VOLUMIO VOLUME 65 Oct 27 11:44:21 volumio2 volumio[26398]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 27 11:44:21 volumio2 volumio[26398]: info: Setting Spotify Volume from Volumio: 65 Oct 27 11:44:22 volumio2 volumio[26398]: SPOTIFY: SETTING SPOTIFY VOLUME 65 Oct 27 11:44:22 volumio2 volumio[26398]: info: Sending Spotify command with payload to local API: /player/volume Oct 27 11:44:22 volumio2 go-librespot[26702]: time="2025-10-27T11:44:22+01:00" level=debug msg="update volume requested to 42597/65535" Oct 27 11:44:23 volumio2 go-librespot[26702]: time="2025-10-27T11:44:23+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 27 11:44:23 volumio2 go-librespot[26702]: time="2025-10-27T11:44:23+01:00" level=trace msg="emitting websocket event: volume" Oct 27 11:44:23 volumio2 volumio[26398]: SPOTIFY: received: {"type":"volume","data":{"value":65,"max":100}} Oct 27 11:44:23 volumio2 volumio[26398]: SPOTIFY: RECEIVED SPOTIFY VOLUME 65 Oct 27 11:44:35 volumio2 go-librespot[26702]: time="2025-10-27T11:44:35+01:00" level=trace msg="sent dealer ping" Oct 27 11:44:35 volumio2 go-librespot[26702]: time="2025-10-27T11:44:35+01:00" level=trace msg="received dealer pong" Oct 27 11:44:35 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPlay Oct 27 11:44:35 volumio2 volumio[26398]: info: CoreStateMachine::play index undefined Oct 27 11:44:35 volumio2 volumio[26398]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 27 11:44:35 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:35 volumio2 volumio[26398]: info: CoreStateMachine::startPlaybackTimer Oct 27 11:44:35 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:35 volumio2 volumio[26398]: info: [1761561875880] ControllerWebradio::clearAddPlayTrack Oct 27 11:44:35 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand stop Oct 27 11:44:35 volumio2 volumio[26398]: info: sendMpdCommand stop took 8 milliseconds Oct 27 11:44:35 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand clear Oct 27 11:44:35 volumio2 volumio[26398]: info: Oct 27 11:44:35 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:35 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:35 volumio2 volumio[26398]: info: sendMpdCommand clear took 6 milliseconds Oct 27 11:44:35 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand load "https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein" Oct 27 11:44:35 volumio2 volumio[26398]: info: Oct 27 11:44:35 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:35 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:35 volumio2 volumio[26398]: info: Oct 27 11:44:35 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:35 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:35 volumio2 volumio[26398]: error: updateQueue error: null Oct 27 11:44:35 volumio2 volumio[26398]: info: ------------------------------ 21ms Oct 27 11:44:38 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand add "https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein" Oct 27 11:44:38 volumio2 volumio[26398]: error: updateQueue error: null Oct 27 11:44:38 volumio2 volumio[26398]: error: updateQueue error: null Oct 27 11:44:38 volumio2 volumio[26398]: info: Oct 27 11:44:38 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:38 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:38 volumio2 volumio[26398]: info: ------------------------------ 2589ms Oct 27 11:44:38 volumio2 volumio[26398]: info: ------------------------------ 2585ms Oct 27 11:44:38 volumio2 volumio[26398]: info: sendMpdCommand add "https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein" took 7 milliseconds Oct 27 11:44:38 volumio2 volumio[26398]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 27 11:44:38 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand play Oct 27 11:44:38 volumio2 volumio[26398]: info: Oct 27 11:44:38 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:38 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:38 volumio2 volumio[26398]: info: Oct 27 11:44:38 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:38 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:38 volumio2 volumio[26398]: info: ------------------------------ 17ms Oct 27 11:44:38 volumio2 volumio[26398]: info: sendMpdCommand play took 12 milliseconds Oct 27 11:44:38 volumio2 volumio[26398]: info: ------------------------------ 11ms Oct 27 11:44:38 volumio2 volumio[26398]: info: ------------------------------ 8ms Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 16 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 13 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 10 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 25 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 19 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 17 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 16 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 12 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 8 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus stop Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:39 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:39 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 132ms Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 244ms Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 242ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 204 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 199 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 198 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:39 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:39 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"low?aggregator=tunein","artist":null,"album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:39 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:39 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 512ms Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 494ms Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 493ms Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Handling event: musicPlay Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] *** musicPlay *** Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:39 volumio2 volumio[26398]: info: [GPIO_Control] Turning GPIO 26 On (musicPlay) Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 45ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 29 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 28ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 24 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 23ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 20 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces system playlist update Oct 27 11:44:39 volumio2 volumio[26398]: info: Ignoring MPD Status Update Oct 27 11:44:39 volumio2 volumio[26398]: info: Oct 27 11:44:39 volumio2 volumio[26398]: ---------------------------- MPD announces state update: player Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::getState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand status Oct 27 11:44:39 volumio2 volumio[26398]: warn: [ROTARYENCODER2] Push Button 2 signalled "released" but was never pressed. Did you set the correct Push Button logic? Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 42ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 37 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 29 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 28 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 27 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 24ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 20 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: info: ------------------------------ 19ms Oct 27 11:44:39 volumio2 volumio[26398]: info: sendMpdCommand status took 14 milliseconds Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::parseState Oct 27 11:44:39 volumio2 volumio[26398]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 27 11:44:39 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:39 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:39 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1358,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:40 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1358,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:40 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1358,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 336ms Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 331ms Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 327ms Oct 27 11:44:40 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 310 milliseconds Oct 27 11:44:40 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 307 milliseconds Oct 27 11:44:40 volumio2 volumio[26398]: info: sendMpdCommand playlistinfo took 307 milliseconds Oct 27 11:44:40 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:40 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:40 volumio2 volumio[26398]: verbose: ControllerMpd::parseTrackInfo Oct 27 11:44:40 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:40 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1358,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:40 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1484,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ControllerMpd::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::servicePushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CorePlayQueue::getTrack 0 Oct 27 11:44:40 volumio2 volumio[26398]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1484,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Alan Parsons Project: Eye In The Sky","artist":"BAYERN 1 Oberbayern","album":null,"uri":"https://dispatcher.rndfnk.com/br/br1/obb/mp3/low?aggregator=tunein","trackType":""} Oct 27 11:44:40 volumio2 volumio[26398]: verbose: CURRENT POSITION 0 Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState stateService play Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::syncState currentStatus play Oct 27 11:44:40 volumio2 volumio[26398]: info: Received an update from plugin. extracting info from payload Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreStateMachine::pushState Oct 27 11:44:40 volumio2 volumio[26398]: info: CoreCommandRouter::volumioPushState Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 594ms Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 574ms Oct 27 11:44:40 volumio2 volumio[26398]: info: ------------------------------ 569ms Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: info: [GPIO_Control] Status changed: play Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: SPOTIFY: RECEIVED VOLUMIO VOLUME 65 Oct 27 11:44:40 volumio2 volumio[26398]: info: touch_display: Setting screensaver timeout to 0 seconds. Oct 27 11:44:41 volumio2 volumio[26398]: info: CALLMETHOD: system_hardware rotaryencoder2 updateEncoder [object Object] Oct 27 11:44:41 volumio2 volumio[26398]: info: CoreCommandRouter::executeOnPlugin: rotaryencoder2 , updateEncoder Oct 27 11:44:41 volumio2 sudo[27433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:41 volumio2 sudo[27433]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:41 volumio2 sudo[27433]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:41 volumio2 sudo[27436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 3 Oct 27 11:44:41 volumio2 sudo[27436]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:41 volumio2 sudo[27436]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:41 volumio2 sudo[27447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:41 volumio2 sudo[27447]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:41 volumio2 sudo[27447]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:41 volumio2 sudo[27450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 2 Oct 27 11:44:41 volumio2 sudo[27450]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:41 volumio2 sudo[27450]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 sudo[27459]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:42 volumio2 sudo[27459]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:42 volumio2 sudo[27459]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 sudo[27462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 1 Oct 27 11:44:42 volumio2 sudo[27462]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:42 volumio2 sudo[27462]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 sudo[27471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:42 volumio2 sudo[27471]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:42 volumio2 sudo[27471]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 sudo[27474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r 0 Oct 27 11:44:42 volumio2 sudo[27474]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:42 volumio2 sudo[27474]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 sudo[27483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=21 pin_b=20 relative_axis=true steps-per-period=1 Oct 27 11:44:42 volumio2 sudo[27483]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:42 volumio2 kernel: rotary-encoder rotary@15: gray Oct 27 11:44:42 volumio2 kernel: input: rotary@15 as /devices/platform/rotary@15/input/input41 Oct 27 11:44:42 volumio2 sudo[27483]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:42 volumio2 systemd-udevd[27443]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:42 volumio2 sudo[27497]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=16 active_low=true gpio_pull=up keycode=20 Oct 27 11:44:42 volumio2 sudo[27497]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:43 volumio2 kernel: input: button@10 as /devices/platform/button@10/input/input42 Oct 27 11:44:43 volumio2 sudo[27497]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:43 volumio2 systemd-udevd[27443]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:43 volumio2 sudo[27510]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=6 pin_b=13 relative_axis=true steps-per-period=1 Oct 27 11:44:43 volumio2 sudo[27510]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:43 volumio2 kernel: rotary-encoder rotary@6: gray Oct 27 11:44:43 volumio2 kernel: input: rotary@6 as /devices/platform/rotary@6/input/input43 Oct 27 11:44:43 volumio2 sudo[27510]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:43 volumio2 sudo[27524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=19 active_low=true gpio_pull=up keycode=20 Oct 27 11:44:43 volumio2 sudo[27524]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:43 volumio2 systemd-udevd[27443]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:43 volumio2 kernel: input: button@13 as /devices/platform/button@13/input/input44 Oct 27 11:44:43 volumio2 sudo[27524]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:43 volumio2 systemd-udevd[27443]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 27 11:44:43 volumio2 sudo[27537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 27 11:44:43 volumio2 sudo[27537]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 27 11:44:43 volumio2 sudo[27537]: pam_unix(sudo:session): session closed for user root Oct 27 11:44:52 volumio2 volumio[26398]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 11:44:52 volumio2 volumio[26398]: SyntaxError: Unexpected token u in JSON at position 0 Oct 27 11:44:52 volumio2 volumio[26398]: at JSON.parse () Oct 27 11:44:52 volumio2 volumio[26398]: at rotaryencoder2.emitPushCommand (/data/plugins/system_hardware/rotaryencoder2/index.js:739:17) Oct 27 11:44:52 volumio2 volumio[26398]: at Timeout._onTimeout (/data/plugins/system_hardware/rotaryencoder2/index.js:622:16) Oct 27 11:44:52 volumio2 volumio[26398]: at listOnTimeout (internal/timers.js:554:17) Oct 27 11:44:52 volumio2 volumio[26398]: at processTimers (internal/timers.js:497:7) Oct 27 11:44:52 volumio2 volumio[26398]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 11:44:53 volumio2 sudo[27566]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-27 11:43 Oct 27 11:44:53 volumio2 sudo[27566]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"