-- Logs begin at Thu 2024-04-25 21:26:54 EDT, end at Thu 2024-04-25 22:14:35 EDT. -- Apr 25 22:13:02 volumio volumio[801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 25 22:13:02 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:09 volumio volumio[801]: info: CALLMETHOD: user_interface peppy_screensaver savePeppyMeterConf [object Object] Apr 25 22:13:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , savePeppyMeterConf Apr 25 22:13:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:09 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:09 volumio volumio[801]: warn: peppy_screensaver: An error occurred when change MPD output Command failed: sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/no/yes/}' /etc/mpd_include.conf Apr 25 22:13:09 volumio volumio[801]: sed: can't read /etc/mpd_include.conf: No such file or directory Apr 25 22:13:09 volumio volumio[801]: {"killed":false,"code":2,"signal":null,"cmd":"sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/no/yes/}' /etc/mpd_include.conf","stack":"Error: Command failed: sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/no/yes/}' /etc/mpd_include.conf\nsed: can't read /etc/mpd_include.conf: No such file or directory\n\n at ChildProcess.exithandler (child_process.js:308:12)\n at ChildProcess.emit (events.js:315:20)\n at maybeClose (internal/child_process.js:1048:16)\n at Socket. (internal/child_process.js:439:11)\n at Socket.emit (events.js:315:20)\n at Pipe. (net.js:673:12)"} Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::clearAddPlayTracks NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3 Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand stop took 57 milliseconds Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clear Apr 25 22:13:13 volumio volumio[801]: info: Apr 25 22:13:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:13 volumio volumio[801]: info: Apr 25 22:13:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand clear took 13 milliseconds Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3" Apr 25 22:13:13 volumio volumio[801]: info: Apr 25 22:13:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:13 volumio volumio[801]: info: Apr 25 22:13:13 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:13 volumio volumio[801]: error: updateQueue error: null Apr 25 22:13:13 volumio volumio[801]: info: Apr 25 22:13:13 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:13 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand status took 50 milliseconds Apr 25 22:13:13 volumio volumio[801]: info: ------------------------------ 59ms Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand add "NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3" took 45 milliseconds Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand status took 35 milliseconds Apr 25 22:13:13 volumio volumio[801]: info: sendMpdCommand status took 18 milliseconds Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand play Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:13 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: 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} Apr 25 22:13:13 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: No code Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: 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} Apr 25 22:13:13 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: No code Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: 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} Apr 25 22:13:13 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState stateService stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:13 volumio volumio[801]: info: No code Apr 25 22:13:13 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:13 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:13 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 1301ms Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 1283ms Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 1279ms Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:14 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:14 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 1285ms Apr 25 22:13:14 volumio volumio[801]: info: sendMpdCommand play took 1274 milliseconds Apr 25 22:13:14 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:14 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 32ms Apr 25 22:13:14 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:14 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:14 volumio volumio[801]: info: ------------------------------ 31ms Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:14 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:14 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:14 volumio volumio[801]: info: Apr 25 22:13:14 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:14 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:14 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:14 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:15 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:15 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand status took 527 milliseconds Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand status took 529 milliseconds Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand status took 523 milliseconds Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clearerror Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand status took 510 milliseconds Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand clearerror took 183 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand clearerror took 179 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand clearerror took 173 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand clearerror took 163 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand playlistinfo took 52 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand playlistinfo took 52 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand playlistinfo took 44 milliseconds Apr 25 22:13:15 volumio volumio[801]: info: sendMpdCommand playlistinfo took 42 milliseconds Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:15 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:15 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:15 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState stateService pause Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:15 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:15 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState stateService pause Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:15 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:15 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState stateService pause Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:15 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:15 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState stateService pause Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:15 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:15 volumio volumio[801]: info: ------------------------------ 1258ms Apr 25 22:13:15 volumio volumio[801]: info: ------------------------------ 1258ms Apr 25 22:13:15 volumio volumio[801]: info: ------------------------------ 1239ms Apr 25 22:13:15 volumio volumio[801]: info: ------------------------------ 1223ms Apr 25 22:13:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:25 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 25 22:13:25 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 25 22:13:26 volumio go-librespot[1657]: time="2024-04-25T22:13:26-04:00" level=error msg="did not receive last pong from dealer, 60s passed" Apr 25 22:13:30 volumio volumio[801]: info: Starting Uninstall of plugin user_interface - peppy_screensaver Apr 25 22:13:30 volumio volumio[801]: info: Uninstalling plugin peppy_screensaver Apr 25 22:13:30 volumio volumio[801]: info: CoreStateMachine::stop Apr 25 22:13:30 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:13:30 volumio sudo[1924]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount /volumio/app/plugins/music_service/mpd/mpd.conf.tmpl Apr 25 22:13:30 volumio sudo[1924]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:30 volumio sudo[1924]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:30 volumio systemd[1]: volumio-app-plugins-music_service-mpd-mpd.conf.tmpl.mount: Succeeded. Apr 25 22:13:30 volumio volumio[801]: info: Disabling plugin peppy_screensaver Apr 25 22:13:30 volumio volumio[801]: info: Preparing to generate the ALSA configuration file Apr 25 22:13:30 volumio sudo[1929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount /volumio/app/plugins/music_service/airplay_emulation/shairport-sync.conf.tmpl Apr 25 22:13:30 volumio sudo[1929]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:30 volumio sudo[1929]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:30 volumio systemd[1]: volumio-app-plugins-music_service-airplay_emulation-shairport\x2dsync.conf.tmpl.mount: Succeeded. Apr 25 22:13:30 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: spop , initializeLibrespotDaemon Apr 25 22:13:30 volumio volumio[801]: info: Creating Spotify config file Apr 25 22:13:30 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:30 volumio volumio[801]: info: Spotify config file written Apr 25 22:13:30 volumio volumio[801]: info: Asound.conf file written Apr 25 22:13:30 volumio sudo[1932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 25 22:13:30 volumio sudo[1932]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:30 volumio systemd[1]: Stopping go-librespot Daemon... Apr 25 22:13:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 25 22:13:30 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Apr 25 22:13:30 volumio systemd[1]: Stopped go-librespot Daemon. Apr 25 22:13:30 volumio sudo[1935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 25 22:13:30 volumio sudo[1935]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:30 volumio systemd[1]: Started go-librespot Daemon. Apr 25 22:13:30 volumio go-librespot[1936]: Librespot-go daemon starting... Apr 25 22:13:31 volumio sudo[1935]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:31 volumio sudo[1932]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:31 volumio go-librespot[1936]: time="2024-04-25T22:13:31-04:00" level=info msg="generated new device id: a99ba8e554fcfe6b31c7e271deb6c572a93c6c67" Apr 25 22:13:31 volumio go-librespot[1936]: time="2024-04-25T22:13:31-04:00" level=debug msg="stored credentials found for 1249171035" Apr 25 22:13:31 volumio volumio[801]: No state is present for card Dummy Apr 25 22:13:31 volumio volumio[801]: Found hardware: "Dummy" "Dummy Mixer" "" "" "" Apr 25 22:13:31 volumio volumio[801]: Hardware is initialized using a generic method Apr 25 22:13:31 volumio volumio[801]: No state is present for card Dummy Apr 25 22:13:31 volumio volumio[801]: info: Output device has changed, restarting MPD Apr 25 22:13:31 volumio sudo[1948]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 25 22:13:31 volumio sudo[1948]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:31 volumio volumio[801]: info: Output device has changed, restarting Shairport Sync Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:31 volumio sudo[1948]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:31 volumio sudo[1951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 25 22:13:31 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:31 volumio systemd[1]: Stopping Music Player Daemon... Apr 25 22:13:31 volumio volumio[801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 25 22:13:31 volumio volumio[801]: info: Checking if uninstall.sh is present Apr 25 22:13:31 volumio volumio[801]: info: Executing uninstall.sh Apr 25 22:13:31 volumio sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/user_interface/peppy_screensaver/uninstall.sh Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio sudo[1959]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: (node:801) UnhandledPromiseRejectionWarning: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: at connResetException (internal/errors.js:607:14) Apr 25 22:13:31 volumio volumio[801]: at Socket.socketOnEnd (_http_client.js:493:23) Apr 25 22:13:31 volumio volumio[801]: at Socket.emit (events.js:327:22) Apr 25 22:13:31 volumio volumio[801]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 25 22:13:31 volumio volumio[801]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 25 22:13:31 volumio volumio[801]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 25 22:13:31 volumio volumio[801]: (node:801) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) Apr 25 22:13:31 volumio volumio[801]: (node:801) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Apr 25 22:13:31 volumio volumio[801]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Apr 25 22:13:31 volumio volumio[801]: info: MPD Permissions set Apr 25 22:13:31 volumio go-librespot[1936]: time="2024-04-25T22:13:31-04:00" level=debug msg="obtained new client token: AADU9s3tD3RJOzG2xOm3hUKoFW1bJV1aFIO2RDM2AYXSdc26W0QnyyQoTAI1mQvuWhhtDc2T2ePj1Wtx5q/k8dMd97pILnLcaZAXNziYxnWf3LvfwEZnfm9lvIZut/H+WUUIaPrlKyI8t159EqiKuV4IdCL0XwP6tZpQY2zvoh4EucsTpuo3wOUqiQorU8RJjGUUs7iihFlVlkeOSR+zSyMjk1r8fjYwJUzqjA6hmz+Huc5Kl1pSPNaQn8Yv/Ho=" Apr 25 22:13:31 volumio systemd[1]: mpd.service: Succeeded. Apr 25 22:13:31 volumio volumio[801]: info: Connection to go-librespot Websocket closed Apr 25 22:13:31 volumio systemd[1]: Stopped Music Player Daemon. Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio systemd[1]: Starting Music Player Daemon... Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 25 22:13:31 volumio volumio[801]: info: Starting Shairport Sync Apr 25 22:13:31 volumio go-librespot[1936]: time="2024-04-25T22:13:31-04:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 25 22:13:32 volumio sudo[1979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 25 22:13:32 volumio sudo[1979]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 25 22:13:32 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 25 22:13:32 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 25 22:13:32 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 25 22:13:32 volumio go-librespot[1936]: time="2024-04-25T22:13:32-04:00" level=debug msg="completed keyexchange" Apr 25 22:13:32 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 25 22:13:32 volumio sudo[1979]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:32 volumio volumio[801]: info: Shairport-Sync Started Apr 25 22:13:32 volumio go-librespot[1936]: time="2024-04-25T22:13:32-04:00" level=debug msg="completed challenge" Apr 25 22:13:32 volumio go-librespot[1936]: time="2024-04-25T22:13:32-04:00" level=debug msg="authenticated as 1249171035" Apr 25 22:13:33 volumio sudo[1959]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:33 volumio volumio[801]: info: Uninstall script return the error Error: Command failed: echo volumio | sudo -S sh /data/plugins/user_interface/peppy_screensaver/uninstall.sh > /tmp/installog Apr 25 22:13:33 volumio volumio[801]: [137B blob data] Apr 25 22:13:33 volumio volumio[801]: [137B blob data] Apr 25 22:13:33 volumio volumio[801]: /data/plugins/user_interface/peppy_screensaver/uninstall.sh: 9: cd: can't cd to /data/plugins/user_interface/peppy_screensaver Apr 25 22:13:33 volumio volumio[801]: [138B blob data] Apr 25 22:13:33 volumio volumio[801]: df: '/volumio/app/plugins/music_service/mpd/mpd.conf.tmpl'$'\r': No such file or directory Apr 25 22:13:33 volumio volumio[801]: [138B blob data] Apr 25 22:13:33 volumio volumio[801]: internal/modules/cjs/loader.js:883 Apr 25 22:13:33 volumio volumio[801]: throw err; Apr 25 22:13:33 volumio volumio[801]: ^ Apr 25 22:13:33 volumio volumio[801]: [43B blob data] Apr 25 22:13:33 volumio volumio[801]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Apr 25 22:13:33 volumio volumio[801]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Apr 25 22:13:33 volumio volumio[801]: at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:72:12) Apr 25 22:13:33 volumio volumio[801]: at internal/main/run_main_module.js:17:47 { Apr 25 22:13:33 volumio volumio[801]: code: 'MODULE_NOT_FOUND', Apr 25 22:13:33 volumio volumio[801]: requireStack: [] Apr 25 22:13:33 volumio volumio[801]: } Apr 25 22:13:33 volumio volumio[801]: [138B blob data] Apr 25 22:13:33 volumio volumio[801]: /data/plugins/user_interface/peppy_screensaver/uninstall.sh: 36: /data/plugins/user_interface/peppy_screensaver/uninstall.sh: Syntax error: end of file unexpected (expecting "then") Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="authenticated as 1249171035" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="dealer connection opened" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="received connection id: N2RkYTE3ZGQtMDk4OC00ZjRlLTliMTItMmNjNjk5ZDUzNTcwK2RlYWxlcit0Y3A6Ly9ndWMzLWRlYWxlci1hLWhtM3EuZ3VjMy5zcG90aWZ5Lm5ldDo1NzAwKzYwOEVBNUVGMTI2MjVGMzdGQzIwQkVGNDc3NUVCMDM0OThGQzkxMTZBNEM0MEYyMzc1RUJFMUMxMzEzQTJFN0E=" Apr 25 22:13:33 volumio go-librespot[1936]: time="2024-04-25T22:13:33-04:00" level=debug msg="put connect state because NEW_DEVICE" Apr 25 22:13:34 volumio volumio[801]: info: go-librespot daemon successfully initialized Apr 25 22:13:34 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 25 22:13:34 volumio go-librespot[1936]: time="2024-04-25T22:13:34-04:00" level=debug msg="new websocket client" Apr 25 22:13:34 volumio volumio[801]: info: Connection to go-librespot Websocket established Apr 25 22:13:35 volumio mpd[1965]: Apr 25 22:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 25 22:13:35 volumio systemd[1]: Started Music Player Daemon. Apr 25 22:13:35 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Apr 25 22:13:35 volumio volumio[801]: error: updateQueue error: null Apr 25 22:13:37 volumio volumio[801]: info: Initializing connection to go-librespot Websocket Apr 25 22:13:37 volumio go-librespot[1936]: time="2024-04-25T22:13:37-04:00" level=debug msg="new websocket client" Apr 25 22:13:37 volumio volumio[801]: info: Connection to go-librespot Websocket established Apr 25 22:13:37 volumio volumio[801]: info: Getting Spotify volume Apr 25 22:13:37 volumio volumio[801]: info: Spotify volume: 100 Apr 25 22:13:37 volumio volumio[801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 12 Apr 25 22:13:38 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 25 22:13:38 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:38 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:38 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 100 Apr 25 22:13:38 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 40 Apr 25 22:13:38 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:13:38 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 40 Apr 25 22:13:39 volumio volumio[801]: SPOTIFY: SETTING SPOTIFY VOLUME 40 Apr 25 22:13:39 volumio volumio[801]: info: Sending Spotify command with payload to local API: /player/volume Apr 25 22:13:39 volumio go-librespot[1936]: time="2024-04-25T22:13:39-04:00" level=debug msg="update volume to 26214/65535" Apr 25 22:13:39 volumio go-librespot[1936]: time="2024-04-25T22:13:39-04:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 25 22:13:39 volumio go-librespot[1936]: time="2024-04-25T22:13:39-04:00" level=trace msg="emitting websocket event: volume" Apr 25 22:13:39 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":40,"max":100}} Apr 25 22:13:39 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 40 Apr 25 22:13:39 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":40,"max":100}} Apr 25 22:13:39 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 40 Apr 25 22:13:40 volumio volumio[801]: info: Getting Spotify volume Apr 25 22:13:40 volumio volumio[801]: info: Spotify volume: 40 Apr 25 22:13:40 volumio volumio[801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 12 Apr 25 22:13:40 volumio volumio[801]: info: CoreCommandRouter::volumioGetState Apr 25 22:13:40 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:40 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:40 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 25 22:13:40 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 25 22:13:40 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:13:40 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:40 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 25 22:13:40 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:40 volumio volumio[801]: verbose: ControllerMpd::clearAddPlayTracks NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3 Apr 25 22:13:40 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 25 22:13:40 volumio volumio[801]: info: sendMpdCommand stop took 2 milliseconds Apr 25 22:13:40 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand clear Apr 25 22:13:40 volumio volumio[801]: info: Apr 25 22:13:40 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:40 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:40 volumio volumio[801]: info: sendMpdCommand clear took 3 milliseconds Apr 25 22:13:40 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3" Apr 25 22:13:40 volumio volumio[801]: error: updateQueue error: null Apr 25 22:13:40 volumio volumio[801]: info: Apr 25 22:13:40 volumio volumio[801]: ---------------------------- MPD announces system playlist update Apr 25 22:13:40 volumio volumio[801]: info: Ignoring MPD Status Update Apr 25 22:13:40 volumio volumio[801]: info: ------------------------------ 17ms Apr 25 22:13:40 volumio volumio[801]: info: sendMpdCommand add "NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3" took 14 milliseconds Apr 25 22:13:40 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand play Apr 25 22:13:40 volumio volumio[801]: info: ------------------------------ 5ms Apr 25 22:13:40 volumio volumio[801]: info: sendMpdCommand play took 4 milliseconds Apr 25 22:13:41 volumio volumio[801]: info: Apr 25 22:13:41 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:41 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:41 volumio volumio[801]: info: Apr 25 22:13:41 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:13:41 volumio volumio[801]: info: sendMpdCommand status took 59 milliseconds Apr 25 22:13:41 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:41 volumio volumio[801]: info: sendMpdCommand status took 6 milliseconds Apr 25 22:13:41 volumio volumio[801]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:41 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:41 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:41 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:41 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:41 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:13:41 volumio volumio[801]: info: ------------------------------ 90ms Apr 25 22:13:41 volumio volumio[801]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 25 22:13:41 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:13:41 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:13:41 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:13:41 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:41 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":362,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2 Minutes to Midnight","artist":"Iron Maiden","album":"Powerslave","uri":"NAS/Music/Iron Maiden/Powerslave/02. 2 Minutes To Midnight.mp3","trackType":"mp3"} Apr 25 22:13:41 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 25 22:13:41 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:41 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:41 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:41 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:41 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:41 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:41 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:41 volumio volumio[801]: info: ------------------------------ 180ms Apr 25 22:13:41 volumio volumio[801]: info: [LastFM] Current track has sufficient metadata: title (2 Minutes to Midnight) and artist (Iron Maiden) passed on explicitly Apr 25 22:13:41 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:41 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 25 22:13:42 volumio volumio[801]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"2 Minutes to Midnight","mbid":"3b863253-035c-4520-81be-b5a644539f0f","url":"https://www.last.fm/music/Iron+Maiden/_/2+Minutes+to+Midnight","duration":"363000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"482757","playcount":"3580018","artist":{"name":"Iron Maiden","mbid":"ca891d65-d9b0-4258-89f7-e6ba29d83767","url":"https://www.last.fm/music/Iron+Maiden"},"album":{"@":{"position":"2"},"artist":"Iron Maiden","title":"Powerslave","mbid":"556c0066-8114-33ad-aa45-ab2f203e2777","url":"https://www.last.fm/music/Iron+Maiden/Powerslave","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/fb8a432b8a23a386b9fbaaa4756800b2.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/fb8a432b8a23a386b9fbaaa4756800b2.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/fb8a432b8a23a386b9fbaaa4756800b2.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/fb8a432b8a23a386b9fbaaa4756800b2.png","@":{"size":"extralarge"}}]},"userplaycount":"1","userloved":"0","toptags":{"tag":[{"name":"heavy metal","url":"https://www.last.fm/tag/heavy+metal"},{"name":"metal","url":"https://www.last.fm/tag/metal"},{"name":"Iron Maiden","url":"https://www.last.fm/tag/Iron+Maiden"},{"name":"NWOBHM","url":"https://www.last.fm/tag/NWOBHM"},{"name":"rock","url":"https://www.last.fm/tag/rock"}]},"wiki":{"published":"24 Jul 2008, 22:09","summary":"\"2 Minutes to Midnight\" is the tenth single released by Iron Maiden and the second track from their 1984 album Powerslave. The single was released on August 6, 1984 and rose to number 11 in the UK Singles Chart. The song was written by Adrian Smith and Bruce Dickinson. The song has references to the Doomsday Clock, the symbolic clock used by the Bulletin of the Atomic Scientists. In September 1953 the clock reached 11:58, the closest the clock ever got to midnight. Read more on Last.fm.","content":"\"2 Minutes to Midnight\" is the tenth single released by Iron Maiden and the second track from their 1984 album Powerslave. The single was released on August 6, 1984 and rose to number 11 in the UK Singles Chart. The song was written by Adrian Smith and Bruce Dickinson. The song has references to the Doomsday Clock, the symbolic clock used by the Bulletin of the Atomic Scientists. In September 1953 the clock reached 11:58, the closest the clock ever got to midnight. This occurred when the United States and Soviet Union tested H-bombs within nine months of one another. This song is clearly presenting an anti-war view. The first guitar solo is played by Dave Murray followed by a guitar solo played by Adrian Smith. The first B-side is a cover of British progressive rock band Beckett's \"Rainbow's Gold\". Another B-side, entitled \"Mission from 'Arry\", is a recording of an argument between bassist Steve Harris and drummer Nicko McBrain. The argument happened after a show in Allentown, Pennsylvania during the band's World Piece Tour, and occurred due to a misunderstanding on stage between the two due to technical issues with Harris' bass, which had led to McBrain's drum solo going wrong. Vocalist Bruce Dickinson was recording the argument with a concealed tape recorder. Trivia The video of the song is featured on the 2003 video collection Visions of the Beast. The song was included in Grand Theft Auto: Vice City. United States Ambassador Ryan Crocker has a poster of the album in his office. [1] The guitar riff in the beginning has been adapted in many other metal songs including: \"Welcome to Hell\" by Venom, \"Hellbound\" by Tygers of Pan Tang, \"Flash Rockin' Man\" by Accept and \"Live Fast Die Young\" by Saxon. The song was covered by the all-female tribute band The Iron Maidens on their self-titled debut album. It was also covered in 2008 by Glamour Of The Kill on the tribute CD Maiden Heaven: A Tribute to Iron Maiden released by Kerrang! magazine. The song is 5 minutes and 59 seconds long, which when doubled yields 11:58, just as the time the song describes. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Apr 25 22:13:44 volumio volumio[801]: info: VolumeController::SetAlsaVolume30 Apr 25 22:13:44 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:44 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:44 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:44 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 40 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 30 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:13:44 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 30 Apr 25 22:13:44 volumio volumio[801]: info: VolumeController::SetAlsaVolume15 Apr 25 22:13:44 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:44 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:44 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:44 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 30 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 15 Apr 25 22:13:44 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:13:44 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 15 Apr 25 22:13:45 volumio volumio[801]: info: VolumeController::SetAlsaVolume25 Apr 25 22:13:45 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:13:45 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:13:45 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:13:45 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:13:45 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Apr 25 22:13:45 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 15 Apr 25 22:13:45 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 25 Apr 25 22:13:45 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:13:45 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 25 Apr 25 22:13:46 volumio volumio[801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 25 22:13:46 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:47 volumio volumio[801]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Apr 25 22:13:47 volumio volumio[801]: info: Sending Spotify command with payload to local API: /player/volume Apr 25 22:13:47 volumio go-librespot[1936]: time="2024-04-25T22:13:47-04:00" level=debug msg="update volume to 16383/65535" Apr 25 22:13:47 volumio go-librespot[1936]: time="2024-04-25T22:13:47-04:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 25 22:13:47 volumio go-librespot[1936]: time="2024-04-25T22:13:47-04:00" level=trace msg="emitting websocket event: volume" Apr 25 22:13:47 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":25,"max":100}} Apr 25 22:13:47 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 25 Apr 25 22:13:47 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":25,"max":100}} Apr 25 22:13:47 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 25 Apr 25 22:13:56 volumio volumio[801]: info: CALLMETHOD: user_interface peppy_screensaver savePeppyMeterConf [object Object] Apr 25 22:13:56 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , savePeppyMeterConf Apr 25 22:13:56 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:56 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:56 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 25 22:13:56 volumio volumio[801]: warn: peppy_screensaver: An error occurred when change MPD output Command failed: sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/yes/no/}' /etc/mpd_include.conf Apr 25 22:13:56 volumio volumio[801]: sed: can't read /etc/mpd_include.conf: No such file or directory Apr 25 22:13:56 volumio volumio[801]: {"killed":false,"code":2,"signal":null,"cmd":"sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/yes/no/}' /etc/mpd_include.conf","stack":"Error: Command failed: sed -i '/---> output peppymeter/,+2{/---> output peppymeter/,+1{b};s/yes/no/}' /etc/mpd_include.conf\nsed: can't read /etc/mpd_include.conf: No such file or directory\n\n at ChildProcess.exithandler (child_process.js:308:12)\n at ChildProcess.emit (events.js:315:20)\n at maybeClose (internal/child_process.js:1048:16)\n at Socket. (internal/child_process.js:439:11)\n at Socket.emit (events.js:315:20)\n at Pipe. (net.js:673:12)"} Apr 25 22:14:00 volumio volumio[801]: info: CALLMETHOD: user_interface peppy_screensaver saveVUMeterConf [object Object] Apr 25 22:14:00 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , saveVUMeterConf Apr 25 22:14:04 volumio volumio[801]: info: VolumeController::SetAlsaVolume30 Apr 25 22:14:04 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:04 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:04 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:04 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 25 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 30 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:14:04 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 30 Apr 25 22:14:04 volumio volumio[801]: info: VolumeController::SetAlsaVolume35 Apr 25 22:14:04 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:04 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:04 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:04 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 30 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 35 Apr 25 22:14:04 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:14:04 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 35 Apr 25 22:14:05 volumio volumio[801]: info: VolumeController::SetAlsaVolume50 Apr 25 22:14:05 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:05 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:05 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:05 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:05 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 25 22:14:05 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 35 Apr 25 22:14:05 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 50 Apr 25 22:14:05 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:14:05 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 50 Apr 25 22:14:05 volumio volumio[801]: info: VolumeController::SetAlsaVolume60 Apr 25 22:14:05 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:05 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:06 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:06 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:06 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:06 volumio volumio[801]: SPOTIFY: SPOTIFY VOLUME 50 Apr 25 22:14:06 volumio volumio[801]: SPOTIFY: VOLUMIO VOLUME 60 Apr 25 22:14:06 volumio volumio[801]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 25 22:14:06 volumio volumio[801]: info: Setting Spotify Volume from Volumio: 60 Apr 25 22:14:07 volumio volumio[801]: SPOTIFY: SETTING SPOTIFY VOLUME 60 Apr 25 22:14:07 volumio volumio[801]: info: Sending Spotify command with payload to local API: /player/volume Apr 25 22:14:07 volumio go-librespot[1936]: time="2024-04-25T22:14:07-04:00" level=debug msg="update volume to 39321/65535" Apr 25 22:14:07 volumio go-librespot[1936]: time="2024-04-25T22:14:07-04:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 25 22:14:07 volumio go-librespot[1936]: time="2024-04-25T22:14:07-04:00" level=trace msg="emitting websocket event: volume" Apr 25 22:14:07 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":60,"max":100}} Apr 25 22:14:07 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 60 Apr 25 22:14:07 volumio volumio[801]: SPOTIFY: received: {"type":"volume","data":{"value":60,"max":100}} Apr 25 22:14:07 volumio volumio[801]: SPOTIFY: RECEIVED SPOTIFY VOLUME 60 Apr 25 22:14:15 volumio volumio[801]: info: Preload queue cleared Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::ClearQueue Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::stop Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::stPlaybackTimer Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::serviceStop Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::serviceStop Apr 25 22:14:15 volumio volumio[801]: info: ControllerMpd::stop Apr 25 22:14:15 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand stop Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::clearPlayQueue Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::addQueueItems Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::addQueueItems Apr 25 22:14:15 volumio volumio[801]: info: Preload queue cleared Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:7i9763l5SSfOnqZ35VOcfy Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:7i9763l5SSfOnqZ35VOcfy Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:2Z8WuEywRWYTKe1NybPQEW Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:2Z8WuEywRWYTKe1NybPQEW Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:1s9xuJxhYM0LdVqksjegcg Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:1s9xuJxhYM0LdVqksjegcg Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:3bnVBN67NBEzedqQuWrpP4 Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:3bnVBN67NBEzedqQuWrpP4 Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:2P61EK6DMGyVyssLWS4fKy Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:2P61EK6DMGyVyssLWS4fKy Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:1lguQJjlNrIOoOylYVZN3M Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:1lguQJjlNrIOoOylYVZN3M Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:57yL3161hUMuw06zzzUCHi Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:57yL3161hUMuw06zzzUCHi Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:6GmkJJMe9U1tEcrJ3Hq3A1 Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:6GmkJJMe9U1tEcrJ3Hq3A1 Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:22OqansuvEMQu9W0EfiGTI Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:22OqansuvEMQu9W0EfiGTI Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:4Oyl6oYSNeeZZP0OAxPVaU Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:4Oyl6oYSNeeZZP0OAxPVaU Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:40sRwFjfrRnaTdYPJIg4CP Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:40sRwFjfrRnaTdYPJIg4CP Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:7qxjGHW485TL8ciwkHD5MK Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:7qxjGHW485TL8ciwkHD5MK Apr 25 22:14:15 volumio volumio[801]: info: Adding Item to queue: spotify:track:5P3yUXUC9rZPJPNmYGKEAz Apr 25 22:14:15 volumio volumio[801]: info: Using cached record of: spotify:track:5P3yUXUC9rZPJPNmYGKEAz Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::volumioPushQueue Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::saveQueue Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::updateTrackBlock Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrackBlock Apr 25 22:14:15 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::play index 1 Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::stop Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:15 volumio volumio[801]: info: CoreStateMachine::startPlaybackTimer Apr 25 22:14:15 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:15 volumio volumio[801]: info: [1714097655987] ControllerSpotify::clearAddPlayTrack Apr 25 22:14:15 volumio volumio[801]: info: Sending Spotify command with payload to local API: /player/play Apr 25 22:14:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:16 volumio volumio[801]: info: Apr 25 22:14:16 volumio volumio[801]: ---------------------------- MPD announces state update: player Apr 25 22:14:16 volumio volumio[801]: info: sendMpdCommand stop took 189 milliseconds Apr 25 22:14:16 volumio volumio[801]: info: ControllerMpd::getState Apr 25 22:14:16 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand status Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="loading track spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn (paused: false, position: 1ms)" Apr 25 22:14:16 volumio volumio[801]: info: sendMpdCommand status took 76 milliseconds Apr 25 22:14:16 volumio volumio[801]: verbose: ControllerMpd::parseState Apr 25 22:14:16 volumio volumio[801]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 25 22:14:16 volumio volumio[801]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 25 22:14:16 volumio volumio[801]: verbose: ControllerMpd::parseTrackInfo Apr 25 22:14:16 volumio volumio[801]: info: ControllerMpd::pushState Apr 25 22:14:16 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:14:16 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:16 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:16 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:16 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:16 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:16 volumio volumio[801]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Apr 25 22:14:16 volumio volumio[801]: info: ------------------------------ 166ms Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1900" Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=trace msg="emitting websocket event: will_play" Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1896" Apr 25 22:14:16 volumio volumio[801]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","play_origin":"go-librespot"}} Apr 25 22:14:16 volumio volumio[801]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","play_origin":"go-librespot"}} Apr 25 22:14:16 volumio volumio[801]: info: touch_display: Setting screensaver timeout to 161 seconds. Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="selected format OGG_VORBIS_160 for spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn" Apr 25 22:14:16 volumio go-librespot[1936]: time="2024-04-25T22:14:16-04:00" level=debug msg="requested aes key for file 3711c8120b29d9ed3865aee94985e0d9bbc8f643, gid: 3CRDbSIZ4r5MsZ0YwxuEkn" Apr 25 22:14:16 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=debug msg="fetched first chunk of 8, total size is 3980500 bytes" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=trace msg="seek to 1ms (diff: -430ms, samples: 44, bytes: 0)" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=info msg="loaded track \"Stressed Out\" (uri: spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn, paused: false, position: 1ms, duration: 202333ms)" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=debug msg="vorbis: corrupt or missing data in bitstream" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=trace msg="emitting websocket event: metadata" Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","name":"Stressed Out","artist_names":["Twenty One Pilots"],"album_name":"Blurryface","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","position":1,"duration":202333,"release_date":"year:2015 month:5 day:15","track_number":2,"disc_number":1}} Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","name":"Stressed Out","artist_names":["Twenty One Pilots"],"album_name":"Blurryface","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","position":1,"duration":202333,"release_date":"year:2015 month:5 day:15","track_number":2,"disc_number":1}} Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=trace msg="emitting websocket event: playing" Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","play_origin":"go-librespot"}} Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: PUSH STATE SPOTIFY Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus stop Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","play_origin":"go-librespot"}} Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: PUSH STATE SPOTIFY Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 25 22:14:17 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:17 volumio go-librespot[1936]: time="2024-04-25T22:14:17-04:00" level=debug msg="fetched chunk 1/7, size: 524288" Apr 25 22:14:17 volumio volumio[801]: info: [LastFM] Current track has sufficient metadata: title (Stressed Out) and artist (Twenty One Pilots) passed on explicitly Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::volumioPlay Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::play index undefined Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: PUSH STATE SPOTIFY Apr 25 22:14:17 volumio volumio[801]: SPOTIFY: {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:17 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 25 22:14:17 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 25 22:14:17 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:17 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:17 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:18 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:18 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:18 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:18 volumio go-librespot[1936]: time="2024-04-25T22:14:18-04:00" level=debug msg="fetched chunk 3/7, size: 524288" Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: PUSH STATE SPOTIFY Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:18 volumio volumio[801]: info: CoreCommandRouter::servicePushState Apr 25 22:14:18 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:18 volumio volumio[801]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Stressed Out","artist":"Twenty One Pilots","album":"Blurryface","albumart":"https://i.scdn.co/image/ab67616d00001e02352e5ec301a02278ffe53d14","uri":"spotify:track:3CRDbSIZ4r5MsZ0YwxuEkn","trackType":"spotify","seek":1,"duration":202,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"160 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 25 22:14:18 volumio volumio[801]: verbose: CURRENT POSITION 1 Apr 25 22:14:18 volumio volumio[801]: info: CoreStateMachine::syncState stateService play Apr 25 22:14:18 volumio volumio[801]: info: CoreStateMachine::syncState currentStatus play Apr 25 22:14:18 volumio volumio[801]: info: Received an update from plugin. extracting info from payload Apr 25 22:14:18 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:18 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:18 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:18 volumio go-librespot[1936]: time="2024-04-25T22:14:18-04:00" level=debug msg="fetched chunk 2/7, size: 524288" Apr 25 22:14:18 volumio volumio[801]: info: CoreStateMachine::pushState Apr 25 22:14:18 volumio volumio[801]: info: CorePlayQueue::getTrack 1 Apr 25 22:14:18 volumio volumio[801]: info: CoreCommandRouter::volumioPushState Apr 25 22:14:18 volumio volumio[801]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Stressed Out","url":"https://www.last.fm/music/Twenty+One+Pilots/_/Stressed+Out","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1253349","playcount":"12758867","artist":{"name":"Twenty One Pilots","mbid":"a6c6897a-7415-4f8d-b5a5-3a5e05f3be67","url":"https://www.last.fm/music/Twenty+One+Pilots"},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"indie pop","url":"https://www.last.fm/tag/indie+pop"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"indie","url":"https://www.last.fm/tag/indie"},{"name":"alternative hip hop","url":"https://www.last.fm/tag/alternative+hip+hop"},{"name":"hip hop","url":"https://www.last.fm/tag/hip+hop"}]},"wiki":{"published":"06 Aug 2016, 05:24","summary":"\"Stressed Out\" is a song written and recorded by American alternative hip-hop band Twenty One Pilots for their fourth studio album, Blurryface. Written by Tyler Joseph and produced by Mike Elizondo, the lyrics discuss the harsh end of adolescence and the transition to adulthood. The song was released as a single on April 28, 2015 on the Google Play Store and Amazon, and was issued to top 40 radio stations on November 10. \"Stressed Out\" reached number two on the US Billboard Hot 100, and number one on Hot Rock Songs and Mainstream Top 40. Read more on Last.fm.","content":"\"Stressed Out\" is a song written and recorded by American alternative hip-hop band Twenty One Pilots for their fourth studio album, Blurryface. Written by Tyler Joseph and produced by Mike Elizondo, the lyrics discuss the harsh end of adolescence and the transition to adulthood. The song was released as a single on April 28, 2015 on the Google Play Store and Amazon, and was issued to top 40 radio stations on November 10. \"Stressed Out\" reached number two on the US Billboard Hot 100, and number one on Hot Rock Songs and Mainstream Top 40. Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:18 volumio volumio[801]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Apr 25 22:14:28 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 22:14:28 volumio volumio[801]: info: Preload queue cleared Apr 25 22:14:29 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 22:14:29 volumio volumio[801]: info: Preload queue cleared Apr 25 22:14:33 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 22:14:33 volumio volumio[801]: info: Preload queue cleared Apr 25 22:14:34 volumio volumio[801]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Apr 25 22:14:34 volumio volumio[801]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 25 22:14:34 volumio volumio[801]: TypeError: Cannot read property 'length' of undefined Apr 25 22:14:34 volumio volumio[801]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Apr 25 22:14:34 volumio volumio[801]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Apr 25 22:14:34 volumio volumio[801]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Apr 25 22:14:34 volumio volumio[801]: at Parser.emit (events.js:315:20) Apr 25 22:14:34 volumio volumio[801]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Apr 25 22:14:34 volumio volumio[801]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Apr 25 22:14:34 volumio volumio[801]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Apr 25 22:14:34 volumio volumio[801]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Apr 25 22:14:34 volumio volumio[801]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Apr 25 22:14:34 volumio volumio[801]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Apr 25 22:14:34 volumio volumio[801]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Apr 25 22:14:34 volumio volumio[801]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Apr 25 22:14:34 volumio volumio[801]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Apr 25 22:14:34 volumio volumio[801]: at IncomingMessage.emit (events.js:327:22) Apr 25 22:14:34 volumio volumio[801]: at endReadableNT (internal/streams/readable.js:1327:12) Apr 25 22:14:34 volumio volumio[801]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Apr 25 22:14:34 volumio volumio[801]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 25 22:14:35 volumio sudo[2066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-25 22:13 Apr 25 22:14:35 volumio sudo[2066]: 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="b51559ff3f3719e35ff52cb9ccf2ff401b5ecb06" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="9f81dc1810002a5ad8861a42d98d57bc06a5d5d3" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 17 Apr 2024 07:54:00 PM CEST" VOLUMIO_VERSION="3.649" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="9c6dee1ade565aed57d77a70a260b988"