-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Mon 2024-07-15 16:37:27 CEST. -- Jul 15 16:36:05 volumio volumio[991]: info: Enabling plugin peppyspectrum Jul 15 16:36:05 volumio volumio[991]: info: Loading plugin "peppyspectrum"... Jul 15 16:36:06 volumio volumio[991]: info: Preparing to generate the ALSA configuration file Jul 15 16:36:06 volumio volumio[991]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 15 16:36:06 volumio volumio[991]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jul 15 16:36:06 volumio volumio[991]: info: Reading ALSA contributions from plugins. Jul 15 16:36:06 volumio volumio[991]: info: Asound.conf file written Jul 15 16:36:06 volumio sudo[1916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jul 15 16:36:06 volumio sudo[1916]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio sudo[1916]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:06 volumio volumio[991]: info: Output device has changed, restarting MPD Jul 15 16:36:06 volumio sudo[1921]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 15 16:36:06 volumio sudo[1921]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio sudo[1921]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:06 volumio volumio[991]: info: Output device has changed, restarting Shairport Sync Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 15 16:36:06 volumio sudo[1924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 15 16:36:06 volumio sudo[1924]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio systemd[1]: Stopping Music Player Daemon... Jul 15 16:36:06 volumio volumio[991]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 15 16:36:06 volumio volumio[991]: info: PLUGIN START: peppyspectrum Jul 15 16:36:06 volumio systemd[1]: mpd.service: Succeeded. Jul 15 16:36:06 volumio systemd[1]: Stopped Music Player Daemon. Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 15 16:36:06 volumio volumio[991]: info: Preparing to generate the ALSA configuration file Jul 15 16:36:06 volumio volumio[991]: info: Done. Jul 15 16:36:06 volumio volumio[991]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 15 16:36:06 volumio volumio[991]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Jul 15 16:36:06 volumio volumio[991]: info: Reading ALSA contributions from plugins. Jul 15 16:36:06 volumio volumio[991]: info: Jul 15 16:36:06 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:06 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:06 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:06 volumio volumio[991]: error: MPD error: Error: write EPIPE Jul 15 16:36:06 volumio volumio[991]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jul 15 16:36:06 volumio systemd[1]: Starting Music Player Daemon... Jul 15 16:36:06 volumio volumio[991]: info: Jul 15 16:36:06 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:06 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:06 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:06 volumio volumio[991]: error: MPD error: Error: write EPIPE Jul 15 16:36:06 volumio volumio[991]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jul 15 16:36:06 volumio volumio[991]: info: Jul 15 16:36:06 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:06 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:06 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:06 volumio volumio[991]: error: MPD error: Error: write EPIPE Jul 15 16:36:06 volumio volumio[991]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jul 15 16:36:06 volumio volumio[991]: info: Jul 15 16:36:06 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:06 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:06 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:06 volumio volumio[991]: error: MPD error: Error: write EPIPE Jul 15 16:36:06 volumio volumio[991]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jul 15 16:36:06 volumio volumio[991]: info: MPD Permissions set Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::volumioGetState Jul 15 16:36:06 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:06 volumio volumio[991]: error: Upnp client error: Error: This socket has been ended by the other party Jul 15 16:36:06 volumio sudo[1929]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 15 16:36:06 volumio sudo[1929]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio sudo[1929]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:06 volumio volumio[991]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: Starting Shairport Sync Jul 15 16:36:06 volumio sudo[1937]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 15 16:36:06 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 15 16:36:06 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 15 16:36:06 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 15 16:36:06 volumio volumio[991]: info: Asound.conf file unchanged, so no further update is needed Jul 15 16:36:06 volumio volumio[991]: info: Output device has changed, restarting MPD Jul 15 16:36:06 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 15 16:36:06 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:06 volumio volumio[991]: info: Output device has changed, restarting Shairport Sync Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 15 16:36:06 volumio sudo[1944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 15 16:36:06 volumio sudo[1944]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio sudo[1941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 15 16:36:06 volumio sudo[1941]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:06 volumio sudo[1941]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:06 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jul 15 16:36:06 volumio systemd[1]: mpd.service: Succeeded. Jul 15 16:36:06 volumio systemd[1]: Stopped Music Player Daemon. Jul 15 16:36:06 volumio systemd[1]: Starting Music Player Daemon... Jul 15 16:36:06 volumio volumio[991]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 15 16:36:06 volumio volumio[991]: info: MPD Permissions set Jul 15 16:36:06 volumio volumio[991]: info: Shairport-Sync Started Jul 15 16:36:06 volumio sudo[1951]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 15 16:36:06 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:07 volumio volumio[991]: info: Starting Shairport Sync Jul 15 16:36:07 volumio sudo[1962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 15 16:36:07 volumio sudo[1962]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:07 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 15 16:36:07 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 15 16:36:07 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 15 16:36:07 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 15 16:36:07 volumio sudo[1962]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:07 volumio volumio[991]: info: Shairport-Sync Started Jul 15 16:36:07 volumio mpd[1956]: Jul 15 16:36 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 15 16:36:07 volumio systemd[1]: Started Music Player Daemon. Jul 15 16:36:07 volumio sudo[1944]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:07 volumio sudo[1924]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:07 volumio volumio[991]: error: MPD error: The expression evaluated to a falsy value: Jul 15 16:36:07 volumio volumio[991]: assert.ok(self.idling) Jul 15 16:36:07 volumio volumio[991]: error: The expression evaluated to a falsy value: Jul 15 16:36:07 volumio volumio[991]: assert.ok(self.idling) Jul 15 16:36:07 volumio volumio[991]: error: updateQueue error: null Jul 15 16:36:08 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:08 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 15 16:36:08 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 15 16:36:09 volumio volumio[991]: info: Enabling plugin now_playing Jul 15 16:36:09 volumio volumio[991]: info: Loading plugin "now_playing"... Jul 15 16:36:10 volumio volumio[991]: info: PLUGIN START: now_playing Jul 15 16:36:10 volumio volumio[991]: info: [now-playing] ConfigUpdater: config version unavailable. Either this is the first time the plugin is installed, or the previous version is < 0.3.0). Config will not be updated. Jul 15 16:36:10 volumio volumio[991]: info: [now-playing] ConfigUpdater: updated config version to 0.6.0 Jul 15 16:36:10 volumio volumio[991]: info: [now-playing] App is listening on port 4004. Jul 15 16:36:10 volumio volumio[991]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 15 16:36:10 volumio volumio[991]: info: Done. Jul 15 16:36:10 volumio volumio[991]: error: Upnp client error: Error: This socket has been ended by the other party Jul 15 16:36:29 volumio volumio[991]: info: CoreCommandRouter::volumioGetQueue Jul 15 16:36:29 volumio volumio[991]: info: CoreStateMachine::getQueue Jul 15 16:36:29 volumio volumio[991]: info: CorePlayQueue::getQueue Jul 15 16:36:32 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Jul 15 16:36:32 volumio volumio[991]: info: [1721054192747] [80s80s] handleBrowseUri curUri: 80s80s Jul 15 16:36:32 volumio volumio[991]: info: Preload queue cleared Jul 15 16:36:34 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri Jul 15 16:36:34 volumio volumio[991]: info: [1721054194148] [80s80s] handleBrowseUri curUri: 80s80s/nineties Jul 15 16:36:34 volumio volumio[991]: info: [1721054194148] [80s80s] getRadioContent url: nineties Jul 15 16:36:34 volumio volumio[991]: info: Preload queue cleared Jul 15 16:36:35 volumio volumio[991]: info: Preload queue cleared Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::ClearQueue Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::stop Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::clearPlayQueue Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::saveQueue Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioPushQueue Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::addQueueItems Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::addQueueItems Jul 15 16:36:35 volumio volumio[991]: info: Preload queue cleared Jul 15 16:36:35 volumio volumio[991]: info: Adding Item to queue: webnineties/0 Jul 15 16:36:35 volumio volumio[991]: info: Exploding uri webnineties/0 in service 80s80s Jul 15 16:36:35 volumio volumio[991]: info: [1721054195303] [80s80s] explodeUri: webnineties/0 Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioPushQueue Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::saveQueue Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::updateTrackBlock Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrackBlock Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioPlay Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::play index 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::stop Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::play index undefined Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::startPlaybackTimer Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: [1721054195317] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/pop/mp3-192/volumio Jul 15 16:36:35 volumio volumio[991]: info: [1721054195317] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=141&count=2 Jul 15 16:36:35 volumio volumio[991]: info: [1721054195480] [80s80s] received new event containing 2 songs. Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand stop Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand stop took 1 milliseconds Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand clear Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:35 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand clear took 2 milliseconds Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand consume 1 Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:35 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:35 volumio volumio[991]: error: updateQueue error: null Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces state update: options Jul 15 16:36:35 volumio volumio[991]: error: updateQueue error: null Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 5ms Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand consume 1 took 4 milliseconds Jul 15 16:36:35 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 3ms Jul 15 16:36:35 volumio volumio[991]: info: [1721054195491] [80s80s] adding url: http://streams.90s90s.de/pop/mp3-192/volumio Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces state update: options Jul 15 16:36:35 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:35 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand status took 4 milliseconds Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" took 4 milliseconds Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand status took 2 milliseconds Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand play Jul 15 16:36:35 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:35 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::pushState Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:35 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::pushState Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 30ms Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 33ms Jul 15 16:36:35 volumio volumio[991]: info: Jul 15 16:36:35 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:35 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 34ms Jul 15 16:36:35 volumio volumio[991]: info: sendMpdCommand play took 29 milliseconds Jul 15 16:36:35 volumio volumio[991]: info: ------------------------------ 4ms Jul 15 16:36:35 volumio volumio[991]: info: [1721054195529] [80s80s] Pushing the next song state: Kate Yanai - Summer Dreamin' (Bacardi Feeling) Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-hits-cover.png","name":"Kate Yanai - Summer Dreamin' (Bacardi Feeling)","title":"Summer Dreamin' (Bacardi Feeling)","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"203","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2} Jul 15 16:36:35 volumio volumio[991]: verbose: CURRENT POSITION 0 Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::syncState stateService play Jul 15 16:36:35 volumio volumio[991]: info: CoreStateMachine::syncState currentStatus stop Jul 15 16:36:35 volumio volumio[991]: info: [1721054195532] [80s80s] PlayNextTrack API delay: 30 Jul 15 16:36:35 volumio volumio[991]: info: [1721054195545] [80s80s] Setting timer to: 203000 milliseconds. Jul 15 16:36:35 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jul 15 16:36:35 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Jul 15 16:36:35 volumio volumio[991]: info: PeppySpectrum ---peppyspectrum status stop Jul 15 16:36:35 volumio volumio[991]: info: PeppySpectrum ---peppyspectrum status stop Jul 15 16:36:35 volumio sudo[1979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jul 15 16:36:35 volumio sudo[1979]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:35 volumio volumio[991]: info: CorePlayQueue::getTrack 1 Jul 15 16:36:35 volumio sudo[1982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service Jul 15 16:36:35 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:35 volumio sudo[1979]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:35 volumio volumio[991]: info: peppyspectrum Daemon Stop Jul 15 16:36:35 volumio sudo[1982]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:35 volumio volumio[991]: info: peppyspectrum Daemon Stop Jul 15 16:36:36 volumio volumio[991]: info: CoreCommandRouter::volumioPlay Jul 15 16:36:36 volumio volumio[991]: info: CoreStateMachine::play index undefined Jul 15 16:36:36 volumio volumio[991]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 15 16:36:36 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 15 16:36:37 volumio volumio[991]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 15 16:36:37 volumio volumio[991]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 15 16:36:37 volumio volumio[991]: info: FusionDsp - Effects disabled Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:37 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 31 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 30 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:37 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 8 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 10ms Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 7 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 8 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 5 milliseconds Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 49ms Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 47ms Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:36:37 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:36:37 volumio volumio[991]: info: Jul 15 16:36:37 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 13ms Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 12 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 10 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 5ms Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand status took 3 milliseconds Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 30ms Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 28ms Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 24ms Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 13 milliseconds Jul 15 16:36:37 volumio volumio[991]: info: sendMpdCommand playlistinfo took 10 milliseconds Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:37 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:37 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:37 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 31ms Jul 15 16:36:37 volumio volumio[991]: info: ------------------------------ 20ms Jul 15 16:36:37 volumio volumio[991]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jul 15 16:36:49 volumio volumio[991]: info: VolumeController::SetAlsaVolume100 Jul 15 16:36:49 volumio volumio[991]: info: [squeezelite_mc] Setting Squeezelite volume to 100 Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::volumioGetState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: CoreStateMachine::pushState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Jul 15 16:36:49 volumio volumio[991]: info: [LastFM] Current track has sufficient metadata: title (Kate Yanai - Summer Dreamin' (Bacardi Feeling)) and artist (90s90s Hits) passed on explicitly Jul 15 16:36:49 volumio volumio[991]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Jul 15 16:36:49 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 15 16:36:49 volumio volumio[991]: SPOTIFY: SPOTIFY VOLUME 30 Jul 15 16:36:49 volumio volumio[991]: SPOTIFY: VOLUMIO VOLUME 100 Jul 15 16:36:49 volumio volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true Jul 15 16:36:49 volumio volumio[991]: info: Setting Spotify Volume from Volumio: 100 Jul 15 16:36:49 volumio volumio[991]: info: PeppySpectrum ---peppyspectrum status play Jul 15 16:36:49 volumio volumio[991]: info: Jul 15 16:36:49 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:49 volumio volumio[991]: info: Jul 15 16:36:49 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand status took 3 milliseconds Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand status took 3 milliseconds Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:49 volumio volumio[991]: info: Jul 15 16:36:49 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:49 volumio sudo[1991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:49 volumio sudo[1991]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:49 volumio volumio[991]: info: ------------------------------ 18ms Jul 15 16:36:49 volumio volumio[991]: info: ------------------------------ 18ms Jul 15 16:36:49 volumio volumio[991]: info: Jul 15 16:36:49 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand status took 5 milliseconds Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand status took 2 milliseconds Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:49 volumio volumio[991]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 15 16:36:49 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:49 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:49 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:49 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:49 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:49 volumio volumio[991]: info: ------------------------------ 16ms Jul 15 16:36:49 volumio volumio[991]: info: ------------------------------ 11ms Jul 15 16:36:49 volumio systemd[1]: Started peppyspectrum Daemon. Jul 15 16:36:49 volumio sudo[1991]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:49 volumio volumio[991]: info: peppyspectrum Daemon Started Jul 15 16:36:49 volumio volumio[1993]: Traceback (most recent call last): Jul 15 16:36:49 volumio volumio[1993]: File "spectrum.py", line 18, in Jul 15 16:36:49 volumio volumio[1993]: import pygame Jul 15 16:36:49 volumio volumio[1993]: ModuleNotFoundError: No module named 'pygame' Jul 15 16:36:49 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Jul 15 16:36:49 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Jul 15 16:36:50 volumio volumio[991]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Jul 15 16:36:50 volumio volumio[991]: info: Sending Spotify command with payload to local API: /player/volume Jul 15 16:36:51 volumio volumio[991]: info: VolumeController::SetAlsaVolume77 Jul 15 16:36:51 volumio volumio[991]: info: [squeezelite_mc] Setting Squeezelite volume to 77 Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::volumioGetState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: CoreStateMachine::pushState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Jul 15 16:36:51 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jul 15 16:36:51 volumio volumio[991]: SPOTIFY: SPOTIFY VOLUME 100 Jul 15 16:36:51 volumio volumio[991]: SPOTIFY: VOLUMIO VOLUME 77 Jul 15 16:36:51 volumio volumio[991]: SPOTIFY: DELTA VOLUME ENOUGH: true Jul 15 16:36:51 volumio volumio[991]: info: Setting Spotify Volume from Volumio: 77 Jul 15 16:36:51 volumio volumio[991]: info: PeppySpectrum ---peppyspectrum status play Jul 15 16:36:51 volumio volumio[991]: info: Jul 15 16:36:51 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:51 volumio volumio[991]: info: Jul 15 16:36:51 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:51 volumio volumio[991]: info: Jul 15 16:36:51 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand status took 5 milliseconds Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand status took 5 milliseconds Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:51 volumio volumio[991]: info: Jul 15 16:36:51 volumio volumio[991]: ---------------------------- MPD announces state update: mixer Jul 15 16:36:51 volumio sudo[1997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppyspectrum.service Jul 15 16:36:51 volumio sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand status took 8 milliseconds Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand status took 3 milliseconds Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:51 volumio volumio[991]: info: ------------------------------ 24ms Jul 15 16:36:51 volumio volumio[991]: info: ------------------------------ 22ms Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 15 16:36:51 volumio volumio[991]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:51 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:51 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:36:51 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:36:51 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:36:51 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:36:51 volumio volumio[991]: info: ------------------------------ 27ms Jul 15 16:36:51 volumio volumio[991]: info: ------------------------------ 21ms Jul 15 16:36:51 volumio systemd[1]: Started peppyspectrum Daemon. Jul 15 16:36:51 volumio sudo[1997]: pam_unix(sudo:session): session closed for user root Jul 15 16:36:51 volumio volumio[991]: info: peppyspectrum Daemon Started Jul 15 16:36:51 volumio volumio[1999]: Traceback (most recent call last): Jul 15 16:36:51 volumio volumio[1999]: File "spectrum.py", line 18, in Jul 15 16:36:51 volumio volumio[1999]: import pygame Jul 15 16:36:51 volumio volumio[1999]: ModuleNotFoundError: No module named 'pygame' Jul 15 16:36:51 volumio systemd[1]: peppyspectrum.service: Main process exited, code=exited, status=1/FAILURE Jul 15 16:36:51 volumio systemd[1]: peppyspectrum.service: Failed with result 'exit-code'. Jul 15 16:36:52 volumio volumio[991]: SPOTIFY: SETTING SPOTIFY VOLUME 77 Jul 15 16:36:52 volumio volumio[991]: info: Sending Spotify command with payload to local API: /player/volume Jul 15 16:37:02 volumio wpa_supplicant[906]: RRM: Ignoring radio measurement request: Not RRM network Jul 15 16:37:04 volumio wpa_supplicant[906]: RRM: Ignoring radio measurement request: Not RRM network Jul 15 16:37:06 volumio wpa_supplicant[906]: RRM: Ignoring radio measurement request: Not RRM network Jul 15 16:37:13 volumio volumio[991]: info: Jul 15 16:37:13 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:37:13 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:37:13 volumio volumio[991]: info: Jul 15 16:37:13 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:37:13 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:37:13 volumio volumio[991]: info: Jul 15 16:37:13 volumio volumio[991]: ---------------------------- MPD announces system playlist update Jul 15 16:37:13 volumio volumio[991]: info: Ignoring MPD Status Update Jul 15 16:37:13 volumio volumio[991]: info: Jul 15 16:37:13 volumio volumio[991]: ---------------------------- MPD announces state update: player Jul 15 16:37:13 volumio volumio[991]: info: ControllerMpd::getState Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand status Jul 15 16:37:13 volumio volumio[991]: info: ------------------------------ 5ms Jul 15 16:37:13 volumio volumio[991]: info: sendMpdCommand status took 3 milliseconds Jul 15 16:37:13 volumio volumio[991]: info: ------------------------------ 3ms Jul 15 16:37:13 volumio volumio[991]: info: sendMpdCommand status took 2 milliseconds Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::parseState Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 15 16:37:13 volumio volumio[991]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 15 16:37:13 volumio volumio[991]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:37:13 volumio volumio[991]: verbose: ControllerMpd::parseTrackInfo Jul 15 16:37:13 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:37:13 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:37:13 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:37:13 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:37:13 volumio volumio[991]: info: ControllerMpd::pushState Jul 15 16:37:13 volumio volumio[991]: info: CoreCommandRouter::servicePushState Jul 15 16:37:13 volumio volumio[991]: info: CorePlayQueue::getTrack 0 Jul 15 16:37:13 volumio volumio[991]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Jul 15 16:37:13 volumio volumio[991]: info: ------------------------------ 9ms Jul 15 16:37:13 volumio volumio[991]: info: ------------------------------ 7ms Jul 15 16:37:26 volumio volumio[991]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Jul 15 16:37:26 volumio volumio[991]: info: PLUGIN onReboot : networkfs Jul 15 16:37:26 volumio volumio[991]: info: PLUGIN onReboot : audiophonicsonoff Jul 15 16:37:26 volumio volumio[991]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 15 16:37:26 volumio volumio[991]: TypeError: Cannot read property 'writeSync' of undefined Jul 15 16:37:26 volumio volumio[991]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25) Jul 15 16:37:26 volumio volumio[991]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Jul 15 16:37:26 volumio volumio[991]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Jul 15 16:37:26 volumio volumio[991]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jul 15 16:37:26 volumio volumio[991]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jul 15 16:37:26 volumio volumio[991]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Jul 15 16:37:26 volumio volumio[991]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22) Jul 15 16:37:26 volumio volumio[991]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:857:33) Jul 15 16:37:26 volumio volumio[991]: at Socket.emit (events.js:315:20) Jul 15 16:37:26 volumio volumio[991]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 15 16:37:26 volumio volumio[991]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 15 16:37:26 volumio volumio[991]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 15 16:37:27 volumio sudo[2054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-15 16:36 Jul 15 16:37:27 volumio sudo[2054]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"