-- Logs begin at Thu 2019-02-14 13:12:00 MSK, end at Sat 2025-11-01 18:18:03 MSK. -- Nov 01 18:17:00 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"277462881","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/277462881","trackType":"qobuz"} Nov 01 18:17:00 volumio volumio[1161]: verbose: CURRENT POSITION 9 Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:00 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:00 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:00 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:00 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"277462881","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/277462881","trackType":"qobuz"} Nov 01 18:17:00 volumio volumio[1161]: verbose: CURRENT POSITION 9 Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:00 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:00 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:00 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:00 volumio volumio[1161]: info: ------------------------------ 444ms Nov 01 18:17:00 volumio volumio[1161]: info: ------------------------------ 386ms Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio sudo[3277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3277]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio sudo[3279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio sudo[3279]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:00 volumio sudo[3277]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:00 volumio sudo[3282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3282]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio sudo[3289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3289]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio sudo[3279]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:00 volumio sudo[3284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3284]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio sudo[3282]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio sudo[3289]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:00 volumio sudo[3294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3294]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:00 volumio volumio[3285]: Traceback (most recent call last): Nov 01 18:17:00 volumio volumio[3285]: File "spectrum.py", line 18, in Nov 01 18:17:00 volumio volumio[3285]: import pygame Nov 01 18:17:00 volumio volumio[3285]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:00 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:00 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:00 volumio sudo[3299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3299]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio sudo[3297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:00 volumio sudo[3297]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:00 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:00 volumio sudo[3294]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:00 volumio sudo[3284]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio sudo[3297]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio sudo[3299]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 1144 milliseconds Nov 01 18:17:01 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:01 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:01 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:01 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:01 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"277462881","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/277462881","trackType":"qobuz"} Nov 01 18:17:01 volumio volumio[1161]: verbose: CURRENT POSITION 9 Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:01 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:01 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:01 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"277462881","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/277462881","trackType":"qobuz"} Nov 01 18:17:01 volumio volumio[1161]: verbose: CURRENT POSITION 9 Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:01 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:01 volumio volumio[3300]: Traceback (most recent call last): Nov 01 18:17:01 volumio volumio[3300]: File "spectrum.py", line 18, in Nov 01 18:17:01 volumio volumio[3300]: import pygame Nov 01 18:17:01 volumio volumio[3300]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:01 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:01 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":189,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"277462881","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/277462881","trackType":"qobuz"} Nov 01 18:17:01 volumio volumio[1161]: verbose: CURRENT POSITION 9 Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:01 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:01 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:01 volumio volumio[1161]: info: ------------------------------ 1647ms Nov 01 18:17:01 volumio volumio[1161]: info: ------------------------------ 1647ms Nov 01 18:17:01 volumio volumio[1161]: info: ------------------------------ 1647ms Nov 01 18:17:01 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:01 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:01 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:01 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:01 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:01 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio sudo[3320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:01 volumio sudo[3320]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio sudo[3322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:01 volumio sudo[3322]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:01 volumio sudo[3325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:01 volumio sudo[3325]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:01 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:01 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:01 volumio sudo[3328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:01 volumio sudo[3328]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:01 volumio sudo[3322]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio sudo[3320]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:01 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:01 volumio sudo[3325]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:01 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:01 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:01 volumio sudo[3332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:01 volumio sudo[3328]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:01 volumio sudo[3332]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio sudo[3334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio sudo[3334]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:02 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:02 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:02 volumio sudo[3332]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:02 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:02 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:02 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:02 volumio sudo[3334]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::ClearQueue Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::stPlaybackTimer Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::serviceStop Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 9 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::serviceStop Nov 01 18:17:02 volumio volumio[1161]: info: [1762010222184] ControllerQobuz::stop Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::stop Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::clearPlayQueue Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:02 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/341173701 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/341173701 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/71600194 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/71600194 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/71600195 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/71600195 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/105731359 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/105731359 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/28186042 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/28186042 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/141784275 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/141784275 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150248 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150248 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/354082106 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/354082106 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/347831895 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/347831895 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/277462881 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/277462881 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/308820586 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/308820586 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/347831900 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/347831900 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/47683544 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/47683544 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:02 volumio volumio[1161]: STREAMING PROXY: Client dropped request, destroying Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPlay Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::play index 12 Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:02 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/129482862 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/129482862 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150247 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150247 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/4087206 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/4087206 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/565479 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/565479 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/73960931 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/73960931 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/78528608 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/78528608 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/28186038 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/28186038 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/37984772 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/37984772 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/129482863 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/129482863 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150250 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150250 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/178468536 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/178468536 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/231566385 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/231566385 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/231566383 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/231566383 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/284882475 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/284882475 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/131659247 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/131659247 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/131659264 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/131659264 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/262538958 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/262538958 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/126296336 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/126296336 Nov 01 18:17:02 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/43588547 Nov 01 18:17:02 volumio volumio[1161]: info: Using cached record of: qobuz://song/43588547 Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::play index undefined Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: [1762010222323] ControllerQobuz::clearAddPlayTrack Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:02 volumio sudo[3338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand stop took 257 milliseconds Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand stop took 121 milliseconds Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:02 volumio sudo[3338]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:02 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:02 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:02 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand status took 31 milliseconds Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand clear took 30 milliseconds Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand status took 27 milliseconds Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand status took 26 milliseconds Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand status took 23 milliseconds Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/47683544" Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:02 volumio volumio[1161]: STREAMING PROXY: Handling url /?data=qobuz://song/47683544 Nov 01 18:17:02 volumio sudo[3338]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:02 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:02 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:02 volumio volumio[1161]: info: ------------------------------ 138ms Nov 01 18:17:02 volumio volumio[1161]: info: ------------------------------ 136ms Nov 01 18:17:02 volumio volumio[1161]: info: ------------------------------ 134ms Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:02 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:02 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:02 volumio volumio[1161]: info: Nov 01 18:17:02 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:02 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:02 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:02 volumio volumio[1161]: info: ------------------------------ 121ms Nov 01 18:17:02 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 117 milliseconds Nov 01 18:17:02 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:02 volumio volumio[1161]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 01 18:17:02 volumio volumio[1161]: info: ------------------------------ 155ms Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:02 volumio sudo[3341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:02 volumio sudo[3341]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:02 volumio sudo[3344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:02 volumio sudo[3344]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio sudo[3341]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio sudo[3347]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:02 volumio sudo[3347]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:02 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:02 volumio volumio[1161]: info: Executing endpoint getStreamUrlqobuz Nov 01 18:17:02 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 01 18:17:02 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:02 volumio sudo[3344]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:02 volumio sudo[3347]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:02 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:03 volumio volumio[1161]: info: getStreamUrl took 303 milliseconds Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3557983&eid=47683544&fmt=27&profile=raw&app_id=539451548&cid=3188029&etsp=1762013823&hmac=kJh7JRzfK72Q4aiI7uXrkIZHdy0 Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Response: 200, length: 225380374 Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/47683544" Nov 01 18:17:03 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:03 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:03 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:03 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 608ms Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 607ms Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 606ms Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Client dropped request, destroying Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/47683544" took 4 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:03 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:03 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Handling url /?data=qobuz://song/47683544 Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:03 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 13ms Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand play took 10 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 9ms Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 7ms Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 5ms Nov 01 18:17:03 volumio volumio[1161]: info: Executing endpoint getStreamUrlqobuz Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 01 18:17:03 volumio volumio[1161]: info: getStreamUrl took 321 milliseconds Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3557983&eid=47683544&fmt=27&profile=raw&app_id=539451548&cid=3188029&etsp=1762013823&hmac=kJh7JRzfK72Q4aiI7uXrkIZHdy0 Nov 01 18:17:03 volumio volumio[1161]: STREAMING PROXY: Response: 200, length: 225380374 Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 24 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 29 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 28 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 25 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 10 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 9 milliseconds Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:03 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:03 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:03 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:03 volumio volumio[1161]: info: ------------------------------ 51ms Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: Nov 01 18:17:03 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand status took 28 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 23 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 23 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 23 milliseconds Nov 01 18:17:03 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 23 milliseconds Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:03 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:03 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:03 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":55,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2746 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:03 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:03 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:03 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:03 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":330,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3020 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:03 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:03 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:03 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:03 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":338,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3020 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:03 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:03 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:03 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:03 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3736 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:03 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:03 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:03 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:04 volumio volumio[1161]: info: ------------------------------ 350ms Nov 01 18:17:04 volumio volumio[1161]: info: ------------------------------ 349ms Nov 01 18:17:04 volumio volumio[1161]: info: ------------------------------ 348ms Nov 01 18:17:04 volumio volumio[1161]: info: ------------------------------ 338ms Nov 01 18:17:04 volumio volumio[1161]: info: sendMpdCommand status took 309 milliseconds Nov 01 18:17:04 volumio volumio[1161]: info: sendMpdCommand status took 307 milliseconds Nov 01 18:17:04 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 302 milliseconds Nov 01 18:17:04 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:04 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:04 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:04 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:04 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:04 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:04 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:04 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":679,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3736 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:04 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:04 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:04 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:04 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:04 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:04 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:04 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:04 volumio volumio[1161]: info: ------------------------------ 416ms Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio sudo[3351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3351]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio sudo[3353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3353]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio sudo[3355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3355]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio sudo[3353]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3359]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio sudo[3362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3362]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3355]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3351]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3359]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3366]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio sudo[3362]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3366]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3369]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3369]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:04 volumio sudo[3372]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio sudo[3374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3374]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:04 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:04 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:04 volumio sudo[3372]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3374]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:04 volumio sudo[3378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:04 volumio sudo[3378]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:05 volumio systemd[1]: peppyspectrum.service: Start request repeated too quickly. Nov 01 18:17:05 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:05 volumio systemd[1]: Failed to start peppyspectrum Daemon. Nov 01 18:17:05 volumio sudo[3378]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:05 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 1025 milliseconds Nov 01 18:17:05 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 1026 milliseconds Nov 01 18:17:05 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:05 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:05 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:05 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:05 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":850,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3939 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:05 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:05 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:05 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:05 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:05 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":850,"duration":355,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"3939 Kbps","isStreaming":false,"title":"47683544","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/47683544","trackType":"qobuz"} Nov 01 18:17:05 volumio volumio[1161]: verbose: CURRENT POSITION 12 Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:05 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:05 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:05 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:05 volumio volumio[1161]: info: ------------------------------ 1459ms Nov 01 18:17:05 volumio volumio[1161]: info: ------------------------------ 1457ms Nov 01 18:17:05 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:05 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum failed to start. Check your configuration Error: Command failed: /usr/bin/sudo /bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: Job for peppyspectrum.service failed because the control process exited with error code. Nov 01 18:17:05 volumio volumio[1161]: See "systemctl status peppyspectrum.service" and "journalctl -xe" for details. Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:05 volumio sudo[3381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:05 volumio sudo[3381]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:05 volumio sudo[3383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio sudo[3383]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:05 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:05 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:05 volumio sudo[3388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio sudo[3390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:05 volumio sudo[3388]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:05 volumio sudo[3390]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:05 volumio sudo[3381]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:05 volumio sudo[3383]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:05 volumio sudo[3388]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:05 volumio sudo[3390]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:05 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:05 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:05 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:05 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:05 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:05 volumio volumio[3387]: Traceback (most recent call last): Nov 01 18:17:05 volumio volumio[3387]: File "spectrum.py", line 18, in Nov 01 18:17:05 volumio volumio[3387]: import pygame Nov 01 18:17:05 volumio volumio[3387]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:05 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:05 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:07 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::ClearQueue Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::stPlaybackTimer Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::serviceStop Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 12 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::serviceStop Nov 01 18:17:07 volumio volumio[1161]: info: [1762010227349] ControllerQobuz::stop Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::stop Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::clearPlayQueue Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:07 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/341173701 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/341173701 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/71600194 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/71600194 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/71600195 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/71600195 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/105731359 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/105731359 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/28186042 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/28186042 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/141784275 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/141784275 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150248 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150248 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/354082106 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/354082106 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/347831895 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/347831895 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/277462881 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/277462881 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/308820586 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/308820586 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/347831900 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/347831900 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:07 volumio volumio[1161]: STREAMING PROXY: Client dropped request, destroying Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPlay Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::play index 11 Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:07 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/47683544 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/47683544 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/129482862 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/129482862 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150247 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150247 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/4087206 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/4087206 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/565479 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/565479 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/73960931 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/73960931 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/78528608 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/78528608 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/28186038 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/28186038 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/37984772 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/37984772 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/129482863 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/129482863 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/161150250 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/161150250 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/178468536 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/178468536 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/231566385 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/231566385 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/231566383 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/231566383 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/284882475 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/284882475 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/131659247 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/131659247 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/131659264 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/131659264 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/262538958 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/262538958 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/126296336 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/126296336 Nov 01 18:17:07 volumio volumio[1161]: info: Adding Item to queue: qobuz://song/43588547 Nov 01 18:17:07 volumio volumio[1161]: info: Using cached record of: qobuz://song/43588547 Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::play index undefined Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: [1762010227457] ControllerQobuz::clearAddPlayTrack Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:07 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand stop took 193 milliseconds Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand stop took 87 milliseconds Nov 01 18:17:07 volumio sudo[3395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:07 volumio sudo[3395]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:07 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand status took 20 milliseconds Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand clear took 19 milliseconds Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand status took 17 milliseconds Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand status took 13 milliseconds Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand status took 10 milliseconds Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/347831900" Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:07 volumio volumio[1161]: STREAMING PROXY: Handling url /?data=qobuz://song/347831900 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:07 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:07 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Nov 01 18:17:07 volumio sudo[3395]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:07 volumio volumio[1161]: info: ------------------------------ 107ms Nov 01 18:17:07 volumio volumio[1161]: info: ------------------------------ 105ms Nov 01 18:17:07 volumio volumio[1161]: info: ------------------------------ 101ms Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:07 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:07 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:07 volumio volumio[1161]: info: Nov 01 18:17:07 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:07 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:07 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:07 volumio volumio[1161]: info: ------------------------------ 99ms Nov 01 18:17:07 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 95 milliseconds Nov 01 18:17:07 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:07 volumio volumio[1161]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 01 18:17:07 volumio volumio[1161]: info: ------------------------------ 122ms Nov 01 18:17:07 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:07 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:07 volumio sudo[3398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:07 volumio sudo[3398]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:07 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:07 volumio sudo[3401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:07 volumio sudo[3401]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:07 volumio sudo[3398]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:07 volumio sudo[3403]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:07 volumio sudo[3403]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:07 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:07 volumio volumio[1161]: info: Executing endpoint getStreamUrlqobuz Nov 01 18:17:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 01 18:17:07 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:07 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:07 volumio sudo[3401]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:07 volumio sudo[3403]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:07 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:07 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:08 volumio volumio[1161]: info: getStreamUrl took 383 milliseconds Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3557983&eid=347831900&fmt=7&profile=raw&app_id=539451548&cid=3188029&etsp=1762013828&hmac=uufd5aO8fFojpHRiSPDrq2ithxw Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Response: 200, length: 139338558 Nov 01 18:17:08 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/347831900" Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 669ms Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 668ms Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 667ms Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:08 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/347831900" took 3 milliseconds Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Client dropped request, destroying Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:08 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:08 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Handling url /?data=qobuz://song/347831900 Nov 01 18:17:08 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 11ms Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand play took 10 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 8ms Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 7ms Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 5ms Nov 01 18:17:08 volumio volumio[1161]: info: Executing endpoint getStreamUrlqobuz Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Nov 01 18:17:08 volumio volumio[1161]: info: getStreamUrl took 254 milliseconds Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3557983&eid=347831900&fmt=7&profile=raw&app_id=539451548&cid=3188029&etsp=1762013828&hmac=uufd5aO8fFojpHRiSPDrq2ithxw Nov 01 18:17:08 volumio volumio[1161]: STREAMING PROXY: Response: 200, length: 139338558 Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 17 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: Nov 01 18:17:08 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 30 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 25 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 22 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 20 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 20 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 15 milliseconds Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:08 volumio volumio[1161]: info: ------------------------------ 62ms Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand status took 32 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 24 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 25 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 25 milliseconds Nov 01 18:17:08 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 19 milliseconds Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:08 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:08 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":41,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2871 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:08 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":78,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2871 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:08 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":105,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2872 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:08 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:08 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:08 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":147,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2857 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:08 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:08 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:08 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:08 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 453ms Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 452ms Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 446ms Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 445ms Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 439ms Nov 01 18:17:09 volumio volumio[1161]: info: Nov 01 18:17:09 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:09 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:09 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:09 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 399 milliseconds Nov 01 18:17:09 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:09 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:09 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:09 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":356,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2844 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:09 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:09 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:09 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:09 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:09 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:09 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:09 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:09 volumio volumio[1161]: info: ------------------------------ 546ms Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3409]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3411]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3414]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3420]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio sudo[3409]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3424]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3424]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio sudo[3420]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio sudo[3411]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio sudo[3414]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio sudo[3428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3428]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3424]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio sudo[3432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio volumio[3421]: Traceback (most recent call last): Nov 01 18:17:09 volumio volumio[3421]: File "spectrum.py", line 18, in Nov 01 18:17:09 volumio volumio[3421]: import pygame Nov 01 18:17:09 volumio volumio[3421]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:09 volumio sudo[3428]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:09 volumio sudo[3432]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:09 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:09 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:09 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:09 volumio sudo[3435]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:09 volumio sudo[3435]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:10 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:10 volumio sudo[3439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3439]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio sudo[3432]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:10 volumio sudo[3444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3435]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio sudo[3444]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio sudo[3439]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:10 volumio sudo[3444]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio sudo[3447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3447]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio sudo[3449]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3449]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio sudo[3447]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio sudo[3449]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:10 volumio volumio[3437]: Traceback (most recent call last): Nov 01 18:17:10 volumio volumio[3437]: File "spectrum.py", line 18, in Nov 01 18:17:10 volumio volumio[3437]: import pygame Nov 01 18:17:10 volumio volumio[3437]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:10 volumio volumio[1161]: info: sendMpdCommand status took 1254 milliseconds Nov 01 18:17:10 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:10 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:10 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:10 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:10 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:10 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:10 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 87 milliseconds Nov 01 18:17:10 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:10 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:10 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:10 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1868,"duration":388,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2846 Kbps","isStreaming":false,"title":"347831900","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/347831900","trackType":"qobuz"} Nov 01 18:17:10 volumio volumio[1161]: verbose: CURRENT POSITION 11 Nov 01 18:17:10 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:10 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:10 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:10 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:10 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:10 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:10 volumio volumio[1161]: info: ------------------------------ 1413ms Nov 01 18:17:10 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:10 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:10 volumio sudo[3453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3453]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio sudo[3455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:10 volumio sudo[3455]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:10 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:10 volumio sudo[3453]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:11 volumio sudo[3455]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:11 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:11 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:11 volumio volumio[3458]: Traceback (most recent call last): Nov 01 18:17:11 volumio volumio[3458]: File "spectrum.py", line 18, in Nov 01 18:17:11 volumio volumio[3458]: import pygame Nov 01 18:17:11 volumio volumio[3458]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:11 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:11 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:11 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:13 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:13 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:13 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:14 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:14 volumio volumio[1161]: info: CURURI: music-library Nov 01 18:17:15 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:16 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:16 volumio volumio[1161]: info: CURURI: music-library/USB Nov 01 18:17:16 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:17 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:17 volumio volumio[1161]: info: CURURI: music-library/USB/465 Nov 01 18:17:17 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:18 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:18 volumio volumio[1161]: info: CURURI: music-library/USB/465/111 Nov 01 18:17:18 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:19 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:19 volumio volumio[1161]: info: CURURI: music-library/USB/465/111/BLUES Nov 01 18:17:19 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 01 18:17:20 volumio volumio[1161]: info: CURURI: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003 Nov 01 18:17:20 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:21 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:21 volumio volumio[1161]: info: CoreCommandRouter::volumioReplaceandPlayItems Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::ClearQueue Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::stPlaybackTimer Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:21 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:21 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:21 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:21 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::serviceStop Nov 01 18:17:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 11 Nov 01 18:17:21 volumio volumio[1161]: info: CoreCommandRouter::serviceStop Nov 01 18:17:21 volumio volumio[1161]: info: [1762010241992] ControllerQobuz::stop Nov 01 18:17:21 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 18:17:21 volumio volumio[1161]: info: ControllerMpd::stop Nov 01 18:17:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::clearPlayQueue Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:22 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/01. Exactly Like You.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/01. Exactly Like You.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/02. On My Word Of Honor.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/02. On My Word Of Honor.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:22 volumio volumio[1161]: STREAMING PROXY: Client dropped request, destroying Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPlay Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::play index 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::addQueueItems Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::addQueueItems Nov 01 18:17:22 volumio volumio[1161]: info: Preload queue cleared Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/04. I'll String Along With You.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/04. I'll String Along With You.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/05. I Need You So.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/05. I Need You So.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/06. A Mother's Love.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/06. A Mother's Love.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/07. (I Love You) For Sentimental Reasons.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/07. (I Love You) For Sentimental Reasons.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/08. Neighborhood Affair.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/08. Neighborhood Affair.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/09. Tomorrow Night.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/09. Tomorrow Night.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/10. There I've Said It Again.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/10. There I've Said It Again.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/11. Always On My Mind.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/11. Always On My Mind.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/12. Cross My Heart.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/12. Cross My Heart.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Adding Item to queue: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/13. What A Wonderful World.dsf Nov 01 18:17:22 volumio volumio[1161]: info: Using cached record of: music-library/USB/465/111/BLUES/B.B. King - Reflections.2003/13. What A Wonderful World.dsf Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushQueue Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::saveQueue Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::play index undefined Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::clearAddPlayTracks USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand stop took 180 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand stop took 83 milliseconds Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:22 volumio sudo[3531]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio sudo[3531]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand status took 15 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand clear took 15 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand status took 12 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand status took 11 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand status took 8 milliseconds Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf" Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 01 18:17:22 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState stateService stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: No code Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 01 18:17:22 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState stateService stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: No code Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Nov 01 18:17:22 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState stateService stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio sudo[3531]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio volumio[1161]: info: No code Nov 01 18:17:22 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:22 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:22 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 255ms Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 254ms Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 254ms Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: error: updateQueue error: null Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 258ms Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 254 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: sendMpdCommand add "USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf" took 254 milliseconds Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 10ms Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 8ms Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 7ms Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:22 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Nov 01 18:17:22 volumio volumio[1161]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Nov 01 18:17:22 volumio volumio[1161]: info: ------------------------------ 278ms Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: Nov 01 18:17:22 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Nov 01 18:17:22 volumio volumio[1161]: info: Ignoring MPD Status Update Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio sudo[3534]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3534]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio sudo[3537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3537]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio sudo[3534]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio sudo[3540]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3540]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio sudo[3544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3544]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio sudo[3537]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio sudo[3540]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio sudo[3547]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3544]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio sudo[3547]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio sudo[3549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3549]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:22 volumio sudo[3547]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio sudo[3553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:22 volumio sudo[3553]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:22 volumio sudo[3549]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:22 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status stop Nov 01 18:17:23 volumio sudo[3556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:23 volumio sudo[3556]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio sudo[3553]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio sudo[3556]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio sudo[3559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Nov 01 18:17:23 volumio sudo[3559]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio sudo[3559]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 819ms Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand play took 815 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 813ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 811ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 809ms Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: peppyspectrum Daemon Stop Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 57 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 56 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 55 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 53 milliseconds Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: Nov 01 18:17:23 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 20 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 17 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 15 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 12 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand status took 11 milliseconds Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1756,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1756,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1756,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1756,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 152ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 198ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 197ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 196ms Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 121 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 119 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 118 milliseconds Nov 01 18:17:23 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 119 milliseconds Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1847,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1847,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1847,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1847,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:23 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:23 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:23 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:23 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 246ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 238ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 236ms Nov 01 18:17:23 volumio volumio[1161]: info: ------------------------------ 235ms Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3562]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3564]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3564]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3568]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:23 volumio sudo[3572]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3572]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3575]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio sudo[3562]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:23 volumio sudo[3579]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:23 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:23 volumio sudo[3572]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio sudo[3564]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:23 volumio sudo[3575]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3579]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3568]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio sudo[3582]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio volumio[3569]: Traceback (most recent call last): Nov 01 18:17:24 volumio volumio[3569]: File "spectrum.py", line 18, in Nov 01 18:17:24 volumio volumio[3569]: import pygame Nov 01 18:17:24 volumio volumio[3569]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:24 volumio sudo[3585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio sudo[3585]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:24 volumio sudo[3587]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3587]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:24 volumio sudo[3592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3592]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio sudo[3596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3596]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio sudo[3582]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:24 volumio sudo[3599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3587]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3592]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3599]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio sudo[3585]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3596]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3601]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio sudo[3599]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio volumio[3590]: Traceback (most recent call last): Nov 01 18:17:24 volumio volumio[3590]: File "spectrum.py", line 18, in Nov 01 18:17:24 volumio volumio[3590]: import pygame Nov 01 18:17:24 volumio volumio[3590]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:24 volumio sudo[3604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:24 volumio sudo[3604]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:24 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:24 volumio sudo[3601]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio sudo[3604]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:24 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:24 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:24 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:24 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:24 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:24 volumio volumio[3607]: Traceback (most recent call last): Nov 01 18:17:24 volumio volumio[3607]: File "spectrum.py", line 18, in Nov 01 18:17:24 volumio volumio[3607]: import pygame Nov 01 18:17:24 volumio volumio[3607]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:24 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioSeek Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::seek Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: TRACKBLOCK {"uri":"mnt/USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","service":"mpd","name":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=771&web=B.B.%20King/Reflections/extralarge&path=%2FUSB%2F465%2F111%2FBLUES%2FB.B.%20King%20-%20Reflections.2003&metadata=false","duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","trackType":"dsf","channels":2} Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::seek Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: error: null Nov 01 18:17:27 volumio volumio[1161]: info: Nov 01 18:17:27 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:27 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:27 volumio volumio[1161]: info: Nov 01 18:17:27 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:27 volumio volumio[1161]: info: Nov 01 18:17:27 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:27 volumio volumio[1161]: info: Nov 01 18:17:27 volumio volumio[1161]: ---------------------------- MPD announces state update: player Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::getState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand status took 99 milliseconds Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand status took 24 milliseconds Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand status took 21 milliseconds Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand status took 18 milliseconds Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 13 milliseconds Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 12 milliseconds Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseState Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27000,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:27 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:27 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio sudo[3610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:27 volumio sudo[3610]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27920,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:27 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:27 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: ------------------------------ 219ms Nov 01 18:17:27 volumio volumio[1161]: info: ------------------------------ 147ms Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 117 milliseconds Nov 01 18:17:27 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 104 milliseconds Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:27 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27920,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:27 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:27 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: ControllerMpd::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: verbose: STATE SERVICE {"status":"play","position":0,"seek":28012,"duration":168,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"I Want A Little Girl","artist":"B.B. King","album":"Reflections","uri":"USB/465/111/BLUES/B.B. King - Reflections.2003/03. I Want A Little Girl.dsf","trackType":"dsf"} Nov 01 18:17:27 volumio volumio[1161]: verbose: CURRENT POSITION 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState stateService play Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus play Nov 01 18:17:27 volumio volumio[1161]: info: Received an update from plugin. extracting info from payload Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreStateMachine::pushState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Nov 01 18:17:27 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:27 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:27 volumio volumio[1161]: info: ------------------------------ 204ms Nov 01 18:17:27 volumio volumio[1161]: info: ------------------------------ 200ms Nov 01 18:17:27 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:27 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:27 volumio sudo[3610]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio sudo[3615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio sudo[3615]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio sudo[3615]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio sudo[3618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio sudo[3618]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio sudo[3620]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio volumio[3612]: Traceback (most recent call last): Nov 01 18:17:28 volumio volumio[3612]: File "spectrum.py", line 18, in Nov 01 18:17:28 volumio volumio[3612]: import pygame Nov 01 18:17:28 volumio volumio[3612]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:28 volumio sudo[3620]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:28 volumio sudo[3622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:28 volumio sudo[3622]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio sudo[3625]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio sudo[3625]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio volumio[1161]: info: PeppySpectrum ---peppyspectrum status play Nov 01 18:17:28 volumio sudo[3629]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio sudo[3629]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio sudo[3632]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio sudo[3632]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio sudo[3635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Nov 01 18:17:28 volumio sudo[3635]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 18:17:28 volumio systemd[1]: Started peppyspectrum Daemon. Nov 01 18:17:28 volumio sudo[3618]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio sudo[3622]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio sudo[3620]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio sudo[3625]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:28 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio sudo[3629]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 01 18:17:28 volumio sudo[3635]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio sudo[3632]: pam_unix(sudo:session): session closed for user root Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[1161]: info: peppyspectrum Daemon Started Nov 01 18:17:28 volumio volumio[3637]: Traceback (most recent call last): Nov 01 18:17:28 volumio volumio[3637]: File "spectrum.py", line 18, in Nov 01 18:17:28 volumio volumio[3637]: import pygame Nov 01 18:17:28 volumio volumio[3637]: ModuleNotFoundError: No module named 'pygame' Nov 01 18:17:28 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Nov 01 18:17:28 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Nov 01 18:17:36 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:36 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 01 18:17:37 volumio volumio[1161]: xcb_connection_has_error() returned true Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 01 18:17:37 volumio volumio[1161]: xcb_connection_has_error() returned true Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 01 18:17:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 01 18:17:38 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:38 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:38 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:41 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:41 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 18:17:43 volumio volumio[1161]: Disk list : [] Nov 01 18:17:43 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:43 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:43 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Nov 01 18:17:43 volumio volumio[1161]: info: Received Get System Version Nov 01 18:17:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 18:17:48 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Nov 01 18:17:48 volumio volumio[1161]: info: CorePlayQueue::getTrack 2 Nov 01 18:17:50 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:50 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:50 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:50 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:50 volumio volumio[1161]: info: Executing endpoint metavolumio Nov 01 18:17:50 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 01 18:17:56 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 01 18:17:56 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 01 18:18:02 volumio volumio[1161]: info: Starting Uninstall of plugin system_controller - ampswitch Nov 01 18:18:02 volumio volumio[1161]: info: Uninstalling plugin ampswitch Nov 01 18:18:02 volumio volumio[1161]: info: [ASDebug] Port: 24 Nov 01 18:18:02 volumio volumio[1161]: info: [ASDebug] Inverted: false Nov 01 18:18:02 volumio volumio[1161]: info: [ASDebug] Delay: 720 Nov 01 18:18:02 volumio volumio[1161]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:18:02 volumio volumio[1161]: TypeError: Cannot read property 'unexport' of undefined Nov 01 18:18:02 volumio volumio[1161]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Nov 01 18:18:02 volumio volumio[1161]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Nov 01 18:18:02 volumio volumio[1161]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Nov 01 18:18:02 volumio volumio[1161]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Nov 01 18:18:02 volumio volumio[1161]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22) Nov 01 18:18:02 volumio volumio[1161]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45) Nov 01 18:18:02 volumio volumio[1161]: at Socket.emit (events.js:315:20) Nov 01 18:18:02 volumio volumio[1161]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 01 18:18:02 volumio volumio[1161]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 01 18:18:02 volumio volumio[1161]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 18:18:03 volumio sudo[3732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 18:17 Nov 01 18:18:03 volumio sudo[3732]: 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"