-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Thu 2025-12-18 22:52:42 CST. --
Dec 18 22:51:03 volumio volumio[18936]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 18 22:51:03 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CALLMETHOD: user_interface peppy_screensaver savePeppyMeterConf [object Object]
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: peppy_screensaver , savePeppyMeterConf
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Dec 18 22:51:09 volumio volumio[18936]: info: Preparing to generate the ALSA configuration file
Dec 18 22:51:09 volumio volumio[18936]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf
Dec 18 22:51:09 volumio volumio[18936]: info: Reading ALSA contributions from plugins.
Dec 18 22:51:09 volumio volumio[18936]: info: Asound.conf file written
Dec 18 22:51:09 volumio sudo[21745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 18 22:51:09 volumio sudo[21745]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:09 volumio sudo[21745]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:09 volumio volumio[18936]: info: Output device has changed, restarting MPD
Dec 18 22:51:09 volumio sudo[21750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 18 22:51:09 volumio sudo[21750]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:09 volumio volumio[18936]: info: Output device has changed, restarting Shairport Sync
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio sudo[21750]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:09 volumio sudo[21752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 18 22:51:09 volumio sudo[21752]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:09 volumio systemd[1]: Stopping Music Player Daemon...
Dec 18 22:51:09 volumio volumio[18936]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Dec 18 22:51:09 volumio volumio[18936]: info: MPD Permissions set
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 22:51:09 volumio systemd[1]: mpd.service: Succeeded.
Dec 18 22:51:09 volumio systemd[1]: Stopped Music Player Daemon.
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 22:51:09 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd
Dec 18 22:51:09 volumio systemd[1]: Starting Music Player Daemon...
Dec 18 22:51:09 volumio volumio[18936]: info: Starting Shairport Sync
Dec 18 22:51:09 volumio sudo[21767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 18 22:51:09 volumio sudo[21767]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:09 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM
Dec 18 22:51:09 volumio systemd[1]: mpd.service: Succeeded.
Dec 18 22:51:09 volumio systemd[1]: Stopped Music Player Daemon.
Dec 18 22:51:09 volumio sudo[21772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Dec 18 22:51:09 volumio sudo[21772]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:10 volumio systemd[1]: Starting Music Player Daemon...
Dec 18 22:51:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Dec 18 22:51:10 volumio systemd[1]: shairport-sync.service: Succeeded.
Dec 18 22:51:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Dec 18 22:51:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Dec 18 22:51:10 volumio sudo[21772]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:10 volumio volumio[18936]: info: Shairport-Sync Started
Dec 18 22:51:10 volumio sudo[21773]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 18 22:51:10 volumio sudo[21773]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 18 22:51:10 volumio sudo[21773]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:10 volumio volumio[18936]: error: Upnp client error: Error: This socket has been ended by the other party
Dec 18 22:51:10 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 18 22:51:12 volumio mpd[21777]: Dec 18 22:51 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 18 22:51:12 volumio systemd[1]: Started Music Player Daemon.
Dec 18 22:51:12 volumio sudo[21752]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:12 volumio sudo[21767]: pam_unix(sudo:session): session closed for user root
Dec 18 22:51:12 volumio volumio[18936]: error: MPD error: The expression evaluated to a falsy value:
Dec 18 22:51:12 volumio volumio[18936]: assert.ok(self.idling)
Dec 18 22:51:12 volumio volumio[18936]: error: The expression evaluated to a falsy value:
Dec 18 22:51:12 volumio volumio[18936]: assert.ok(self.idling)
Dec 18 22:51:12 volumio volumio[18936]: error: updateQueue error: null
Dec 18 22:51:19 volumio volumio[18936]: info: peppy_screensaver: Start PeppyMeter
Dec 18 22:51:26 volumio volumio[18936]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 7
Dec 18 22:51:26 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:29 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:29 volumio volumio[18936]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 8
Dec 18 22:51:29 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:30 volumio volumio[18936]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Simply%20Red/Home/7f6b8f3b-352a-4ebc-9c6e-b84ea42eb15c.png'
Dec 18 22:51:30 volumio volumio[18936]: info: Clearing queue after UPNP request
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::ClearQueue
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::stop
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::stPlaybackTimer
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::updateTrackBlock
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::getTrackBlock
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:30 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 18 22:51:30 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::serviceStop
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:30 volumio volumio[18936]: info: ControllerMpd::stop
Dec 18 22:51:30 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand stop
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::clearPlayQueue
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::saveQueue
Dec 18 22:51:30 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:30 volumio volumio[18936]: info: CoreCommandRouter::volumioPushQueue
Dec 18 22:51:30 volumio volumio[18936]: info:
Dec 18 22:51:30 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:30 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:30 volumio volumio[18936]: info: sendMpdCommand stop took 110 milliseconds
Dec 18 22:51:30 volumio volumio[18936]: error: updateQueue error: null
Dec 18 22:51:30 volumio volumio[18936]: info: ------------------------------ 7ms
Dec 18 22:51:30 volumio volumio[18936]: info:
Dec 18 22:51:30 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:30 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:30 volumio volumio[18936]: info: touch_display: Setting screensaver timeout to 9007199254740991 seconds.
Dec 18 22:51:30 volumio volumio[18936]: error: updateQueue error: null
Dec 18 22:51:30 volumio volumio[18936]: info: ------------------------------ 14ms
Dec 18 22:51:30 volumio volumio[18936]: info: Starting UPNP Playback
Dec 18 22:51:30 volumio volumio[18936]: info: Preparing playback through UPNP
Dec 18 22:51:30 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:30 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:30 volumio volumio[18936]: info: CoreStateMachine::setConsumeUpdateService mpd
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 5ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 2ms
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 2ms
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info:
Dec 18 22:51:31 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:31 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:31 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:32 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand status took 64 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand status took 66 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 9ms
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand status took 6 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 4 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:32 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:32 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:32 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus stop
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 83ms
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:32 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:32 volumio volumio[18936]: info:
Dec 18 22:51:32 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 20 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 18 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 12ms
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand status took 5 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:32 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:32 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:32 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:32 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:32 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:32 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:32 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:32 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 177ms
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 202ms
Dec 18 22:51:32 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 171 milliseconds
Dec 18 22:51:32 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:32 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:32 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:32 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:32 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:32 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:32 volumio volumio[18936]: info: ------------------------------ 228ms
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:32 volumio volumio[18936]: info: peppy_screensaver: Start PeppyMeter
Dec 18 22:51:41 volumio volumio[18936]: info:
Dec 18 22:51:41 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:41 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:41 volumio volumio[18936]: info:
Dec 18 22:51:41 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:41 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:41 volumio volumio[18936]: info: sendMpdCommand status took 4 milliseconds
Dec 18 22:51:41 volumio volumio[18936]: info: sendMpdCommand status took 2 milliseconds
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:41 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 6 milliseconds
Dec 18 22:51:41 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 5 milliseconds
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:41 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:41 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:41 volumio volumio[18936]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:41 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::syncState stateService stop
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::stPlaybackTimer
Dec 18 22:51:41 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:41 volumio volumio[18936]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Put A Little Umph In It","artist":"Jagged Edge","album":"Baby Makin' Project","uri":"http://aqqmusic.tc.qq.com/M8000019v79q0lSjLj.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=6C2549A0FF43F1A2A60D87CBCE22A455F36DF78FDDFC807D50D28EC000E45D7CE04919E6FA553080370521B42D09261B27A7CF3374E3F8E6__v21e2a181d&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:41 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::syncState stateService stop
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus stop
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: No code
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: ------------------------------ 90ms
Dec 18 22:51:41 volumio volumio[18936]: info: ------------------------------ 90ms
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:41 volumio volumio[18936]: info: Clearing queue after UPNP request
Dec 18 22:51:41 volumio volumio[18936]: info: touch_display: Setting screensaver timeout to 9007199254740991 seconds.
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::ClearQueue
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::stop
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::setConsumeUpdateService undefined
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::clearPlayQueue
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::saveQueue
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioPushQueue
Dec 18 22:51:41 volumio volumio[18936]: info:
Dec 18 22:51:41 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:41 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:41 volumio volumio[18936]: info:
Dec 18 22:51:41 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:41 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:41 volumio volumio[18936]: error: updateQueue error: null
Dec 18 22:51:41 volumio volumio[18936]: info: ------------------------------ 6ms
Dec 18 22:51:41 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:41 volumio volumio[18936]: info: Starting UPNP Playback
Dec 18 22:51:41 volumio volumio[18936]: info: Preparing playback through UPNP
Dec 18 22:51:41 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:41 volumio volumio[18936]: info: CorePlayQueue::getTrack 0
Dec 18 22:51:41 volumio volumio[18936]: info: CoreStateMachine::setConsumeUpdateService mpd
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 5ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 2ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 3ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 2ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 4ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 2ms
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand status took 46 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand status took 44 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces system playlist update
Dec 18 22:51:42 volumio volumio[18936]: info: Ignoring MPD Status Update
Dec 18 22:51:42 volumio volumio[18936]: info:
Dec 18 22:51:42 volumio volumio[18936]: ---------------------------- MPD announces state update: player
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::getState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand status
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 14ms
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand status took 11 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 11 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 12 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 11ms
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand status took 10 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseState
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:42 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:42 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sunrise","artist":"Simply Red","album":"Home","uri":"http://aqqmusic.tc.qq.com/M8000005dlEm2HswwA.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=906F3919CDAD220E7F273F8875A6059C5152DCA4B0EE4A0738490B61ACA2F8224DA39E6875652658CBD5F85D512D06F834DE853CD4B2EBD2__v2b94c613&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:42 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus stop
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:42 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:42 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sunrise","artist":"Simply Red","album":"Home","uri":"http://aqqmusic.tc.qq.com/M8000005dlEm2HswwA.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=906F3919CDAD220E7F273F8875A6059C5152DCA4B0EE4A0738490B61ACA2F8224DA39E6875652658CBD5F85D512D06F834DE853CD4B2EBD2__v2b94c613&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:42 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:42 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 101ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 128ms
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 68 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: info: sendMpdCommand playlistinfo took 67 milliseconds
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:42 volumio volumio[18936]: verbose: ControllerMpd::parseTrackInfo
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:42 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:42 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sunrise","artist":"Simply Red","album":"Home","uri":"http://aqqmusic.tc.qq.com/M8000005dlEm2HswwA.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=906F3919CDAD220E7F273F8875A6059C5152DCA4B0EE4A0738490B61ACA2F8224DA39E6875652658CBD5F85D512D06F834DE853CD4B2EBD2__v2b94c613&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:42 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:42 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: ControllerMpd::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::servicePushState
Dec 18 22:51:42 volumio volumio[18936]: verbose: In UPNP mode
Dec 18 22:51:42 volumio volumio[18936]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Sunrise","artist":"Simply Red","album":"Home","uri":"http://aqqmusic.tc.qq.com/M8000005dlEm2HswwA.mp3?guid=ffffffffc73fb5da0000019a973bf78f&vkey=906F3919CDAD220E7F273F8875A6059C5152DCA4B0EE4A0738490B61ACA2F8224DA39E6875652658CBD5F85D512D06F834DE853CD4B2EBD2__v2b94c613&uin=1152921504869461316&redirect=1&fromtag=111093","trackType":""}
Dec 18 22:51:42 volumio volumio[18936]: verbose: CURRENT POSITION 0
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState stateService play
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::syncState currentStatus play
Dec 18 22:51:42 volumio volumio[18936]: info: Received an update from plugin. extracting info from payload
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::pushState
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioPushState
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 306ms
Dec 18 22:51:42 volumio volumio[18936]: info: ------------------------------ 301ms
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreCommandRouter::volumioGetQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CoreStateMachine::getQueue
Dec 18 22:51:42 volumio volumio[18936]: info: CorePlayQueue::getQueue
Dec 18 22:51:54 volumio volumio[18936]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 7
Dec 18 22:51:54 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:57 volumio volumio[18936]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 8
Dec 18 22:51:57 volumio volumio[18936]: info: CoreCommandRouter::volumioGetState
Dec 18 22:51:57 volumio volumio[18936]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Simply%20Red/Home/7f6b8f3b-352a-4ebc-9c6e-b84ea42eb15c.png'
Dec 18 22:52:41 volumio volumio[18936]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 22:52:41 volumio volumio[18936]: Error: connect ETIMEDOUT 104.31.142.88:443
Dec 18 22:52:41 volumio volumio[18936]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) {
Dec 18 22:52:41 volumio volumio[18936]: errno: -110,
Dec 18 22:52:41 volumio volumio[18936]: code: 'ETIMEDOUT',
Dec 18 22:52:41 volumio volumio[18936]: syscall: 'connect',
Dec 18 22:52:41 volumio volumio[18936]: address: '104.31.142.88',
Dec 18 22:52:41 volumio volumio[18936]: port: 443
Dec 18 22:52:41 volumio volumio[18936]: }
Dec 18 22:52:41 volumio volumio[18936]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 18 22:52:42 volumio sudo[22296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-18 22:51
Dec 18 22:52:42 volumio sudo[22296]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="29866754e5f1d7e4d0f581c10d9f22852f6f21db"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST"
VOLUMIO_VERSION="3.832"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"