-- Logs begin at Sat 2024-04-13 11:27:31 MSK, end at Wed 2024-04-17 16:35:01 MSK. --
Apr 17 16:34:16 volumio volumio[704]: info:
Apr 17 16:34:16 volumio volumio[704]: ---------------------------- MPD announces system playlist update
Apr 17 16:34:16 volumio volumio[704]: info: Ignoring MPD Status Update
Apr 17 16:34:16 volumio volumio[704]: info:
Apr 17 16:34:16 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:34:16 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:34:16 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:34:16 volumio volumio[704]: info: ------------------------------ 9ms
Apr 17 16:34:16 volumio volumio[704]: info: sendMpdCommand status took 8 milliseconds
Apr 17 16:34:16 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:34:16 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:34:16 volumio volumio[704]: info: sendMpdCommand playlistinfo took 1 milliseconds
Apr 17 16:34:16 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:34:16 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:34:16 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:34:16 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:16 volumio volumio[704]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":102,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"589 Kbps","isStreaming":false,"title":"Orchestra (Stereo)","artist":"Orchestra (Stereo)","album":"Denon Audio Technical CD","uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.wv","trackType":"wv"}
Apr 17 16:34:16 volumio volumio[704]: verbose: CURRENT POSITION 99
Apr 17 16:34:16 volumio volumio[704]: info: CoreStateMachine::syncState stateService play
Apr 17 16:34:16 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus play
Apr 17 16:34:16 volumio volumio[704]: info: Received an update from plugin. extracting info from payload
Apr 17 16:34:16 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:16 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:16 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:34:16 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:16 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:16 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:16 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:16 volumio volumio[704]: info: ------------------------------ 16ms
Apr 17 16:34:16 volumio volumio[704]: info: [LastFM] Current track has sufficient metadata: title (Channel (L,R)) and artist (Channel (L,R)) passed on explicitly
Apr 17 16:34:16 volumio volumio[704]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Channel (L,R)","url":"https://www.last.fm/music/Channel+(L,R)/_/Channel+(L,R)","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1","playcount":"1","artist":{"name":"Channel (L,R)","url":"https://www.last.fm/music/Channel+(L,R)"},"userplaycount":"2","userloved":"0","toptags":""}}
Apr 17 16:34:25 volumio volumio[704]: verbose: New Socket.io Connection to 192.168.1.34 from 192.168.1.45 UA: unknown Total Clients: 7
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:25 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 17 16:34:25 volumio volumio[704]: info: Discovery: Getting this device information
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:25 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:25 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 17 16:34:26 volumio volumio[704]: verbose: New Socket.io Connection to 192.168.1.34 from 192.168.1.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 16_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 8
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:26 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::volumioGetQueue
Apr 17 16:34:26 volumio volumio[704]: info: CoreStateMachine::getQueue
Apr 17 16:34:26 volumio volumio[704]: info: CorePlayQueue::getQueue
Apr 17 16:34:26 volumio volumio[704]: info: Listing playlists
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 17 16:34:26 volumio volumio[704]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Apr 17 16:34:26 volumio volumio[704]: info: Received Get System Info
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 17 16:34:26 volumio volumio[704]: info: Discovery: Getting this device information
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:26 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:26 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:26 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 17 16:34:27 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:34:27 volumio volumio[704]: info:
Apr 17 16:34:27 volumio volumio[704]: [1713360867893] ---------------------------- Client requests add and Play Volumio CUE entry
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue
Apr 17 16:34:27 volumio volumio[704]: info: Adding CUE individual entry: 1 USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.cue
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioAddQueueItems
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::addQueueItems
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::addQueueItems
Apr 17 16:34:27 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:34:27 volumio volumio[704]: info: Adding Item to queue: cue://USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.cue@1
Apr 17 16:34:27 volumio volumio[704]: info: Exploding uri cue://USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.cue@1 in service mpd
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPlay
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::play index 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::stop
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::stPlaybackTimer
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::updateTrackBlock
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrackBlock
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::serviceStop
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 99
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::serviceStop
Apr 17 16:34:27 volumio volumio[704]: info: ControllerMpd::stop
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand stop
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPushQueue
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::saveQueue
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::updateTrackBlock
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrackBlock
Apr 17 16:34:27 volumio volumio[704]: info:
Apr 17 16:34:27 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:34:27 volumio volumio[704]: info: sendMpdCommand stop took 23 milliseconds
Apr 17 16:34:27 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::play index undefined
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::startPlaybackTimer
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand stop
Apr 17 16:34:27 volumio volumio[704]: info: sendMpdCommand status took 2 milliseconds
Apr 17 16:34:27 volumio volumio[704]: info: sendMpdCommand stop took 1 milliseconds
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand clear
Apr 17 16:34:27 volumio volumio[704]: info: sendMpdCommand playlistinfo took 0 milliseconds
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:34:27 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: 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":"Orchestra (Stereo)","artist":"Orchestra (Stereo)","album":"Denon Audio Technical CD","uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.wv","trackType":"wv"}
Apr 17 16:34:27 volumio volumio[704]: verbose: CURRENT POSITION 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::syncState stateService stop
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus stop
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:27 volumio volumio[704]: info: No code
Apr 17 16:34:27 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:27 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:27 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:27 volumio volumio[704]: info: ------------------------------ 12ms
Apr 17 16:34:27 volumio volumio[704]: info:
Apr 17 16:34:27 volumio volumio[704]: ---------------------------- MPD announces system playlist update
Apr 17 16:34:27 volumio volumio[704]: info: Ignoring MPD Status Update
Apr 17 16:34:27 volumio volumio[704]: info: sendMpdCommand clear took 13 milliseconds
Apr 17 16:34:27 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand load "USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.cue"
Apr 17 16:34:28 volumio volumio[704]: error: updateQueue error: null
Apr 17 16:34:28 volumio volumio[704]: info: ------------------------------ 9ms
Apr 17 16:34:28 volumio volumio[704]: info:
Apr 17 16:34:28 volumio volumio[704]: ---------------------------- MPD announces system playlist update
Apr 17 16:34:28 volumio volumio[704]: info: Ignoring MPD Status Update
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand load "USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.cue" took 9 milliseconds
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand play
Apr 17 16:34:28 volumio volumio[704]: info:
Apr 17 16:34:28 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:34:28 volumio volumio[704]: info: ------------------------------ 13ms
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand play took 14 milliseconds
Apr 17 16:34:28 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:34:28 volumio volumio[704]: info:
Apr 17 16:34:28 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:34:28 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand status took 1 milliseconds
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand status took 3 milliseconds
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:34:28 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:34:28 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:34:28 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:28 volumio volumio[704]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":38,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Balance, Phase (L+R,L-R)","artist":"Balance, Phase (L+R,L-R)","album":"Denon Audio Technical CD","uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.wv","trackType":"wv"}
Apr 17 16:34:28 volumio volumio[704]: verbose: CURRENT POSITION 100
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::syncState stateService play
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus stop
Apr 17 16:34:28 volumio volumio[704]: info: ------------------------------ 8ms
Apr 17 16:34:28 volumio volumio[704]: info: sendMpdCommand playlistinfo took 12 milliseconds
Apr 17 16:34:28 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:34:28 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:34:28 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:34:28 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:28 volumio volumio[704]: verbose: STATE SERVICE {"status":"play","position":1,"seek":0,"duration":38,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Balance, Phase (L+R,L-R)","artist":"Balance, Phase (L+R,L-R)","album":"Denon Audio Technical CD","uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.wv","trackType":"wv"}
Apr 17 16:34:28 volumio volumio[704]: verbose: CURRENT POSITION 100
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::syncState stateService play
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus play
Apr 17 16:34:28 volumio volumio[704]: info: Received an update from plugin. extracting info from payload
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:28 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:28 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:34:28 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:28 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:28 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:28 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:28 volumio volumio[704]: info: ------------------------------ 25ms
Apr 17 16:34:28 volumio volumio[704]: info: [LastFM] Current track has sufficient metadata: title (Balance, Phase (L+R,L-R)) and artist (Balance, Phase (L+R,L-R)) passed on explicitly
Apr 17 16:34:28 volumio volumio[704]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Balance, Phase (L+R,L-R)","url":"https://www.last.fm/music/Balance,+Phase+(L%252BR,L-R)/_/Balance,+Phase+(L%252BR,L-R)","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"30","playcount":"179","artist":{"name":"Balance, Phase (L+R,L-R)","url":"https://www.last.fm/music/Balance,+Phase+(L%252BR,L-R)"},"userplaycount":"2","userloved":"0","toptags":""}}
Apr 17 16:34:40 volumio volumio[704]: info: CoreCommandRouter::volumioPause
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::pause
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::stPlaybackTimer
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::servicePause
Apr 17 16:34:40 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:40 volumio volumio[704]: info: CoreCommandRouter::servicePause
Apr 17 16:34:40 volumio volumio[704]: info: ControllerMpd::pause
Apr 17 16:34:40 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand pause
Apr 17 16:34:40 volumio volumio[704]: info:
Apr 17 16:34:40 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:34:40 volumio volumio[704]: info: sendMpdCommand pause took 1 milliseconds
Apr 17 16:34:40 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:34:40 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:34:40 volumio volumio[704]: info: sendMpdCommand status took 1 milliseconds
Apr 17 16:34:40 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:34:40 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:34:40 volumio volumio[704]: info: sendMpdCommand playlistinfo took 0 milliseconds
Apr 17 16:34:40 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:34:40 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:34:40 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:34:40 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:40 volumio volumio[704]: verbose: STATE SERVICE {"status":"pause","position":1,"seek":12972,"duration":38,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"253 Kbps","isStreaming":false,"title":"Balance, Phase (L+R,L-R)","artist":"Balance, Phase (L+R,L-R)","album":"Denon Audio Technical CD","uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Denon Audio Technical CD Wv/Denon Audio Technical CD.wv","trackType":"wv"}
Apr 17 16:34:40 volumio volumio[704]: verbose: CURRENT POSITION 100
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::syncState stateService pause
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus pause
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:34:40 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:40 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:34:40 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:34:40 volumio volumio[704]: info: CoreStateMachine::stPlaybackTimer
Apr 17 16:34:40 volumio volumio[704]: info: ------------------------------ 5ms
Apr 17 16:34:46 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 17 16:34:46 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 17 16:34:46 volumio volumio[704]: info: Discovery: Getting this device information
Apr 17 16:34:46 volumio volumio[704]: info: CoreCommandRouter::volumioGetState
Apr 17 16:34:46 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:34:46 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 17 16:34:53 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 16:34:53 volumio volumio[704]: info: CURURI: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Various - XLO-RR Test & Burn-In CD Flac
Apr 17 16:34:53 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:34:53 volumio volumio[704]: info: Preloading song: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Various - XLO-RR Test & Burn-In CD Flac/Various - XLO-RR Test & Burn-In CD.flac
Apr 17 16:34:53 volumio volumio[704]: info: Exploding uri music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Various - XLO-RR Test & Burn-In CD Flac/Various - XLO-RR Test & Burn-In CD.flac in service mpd
Apr 17 16:34:53 volumio volumio[704]: info: ALBUMART /albumart?cacheid=877&web=Professor%20Johnson/XLO-RR%20Test%20%26%20Burn-In%20CD/extralarge&path=%2Fmnt%2FUSB%2FSeagate_Expansion_Drive%2FTest%20Audio%20CD%60s%2FVarious%20-%20XLO-RR%20Test%20%26%20Burn-In%20CD%20Flac%2FVarious%20-%20XLO-RR%20Test%20%26%20Burn-In%20CD.flac&metadata=false
Apr 17 16:34:53 volumio volumio[704]: info: URI /mnt/USB/Seagate_Expansion_Drive/Test Audio CD`s/Various - XLO-RR Test & Burn-In CD Flac/Various - XLO-RR Test & Burn-In CD.flac
Apr 17 16:34:56 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 16:34:56 volumio volumio[704]: info: CURURI: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/IsoTek - Full System Enhancer & Rejuvenation Disc Ape
Apr 17 16:34:56 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:34:56 volumio volumio[704]: info: Preloading song: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/IsoTek - Full System Enhancer & Rejuvenation Disc Ape/IsoTek - Full System Enhancer & Rejuvenation Disc.ape
Apr 17 16:34:56 volumio volumio[704]: info: Exploding uri music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/IsoTek - Full System Enhancer & Rejuvenation Disc Ape/IsoTek - Full System Enhancer & Rejuvenation Disc.ape in service mpd
Apr 17 16:34:56 volumio volumio[704]: info: ALBUMART /albumart?cacheid=877&web=//extralarge&path=%2Fmnt%2FUSB%2FSeagate_Expansion_Drive%2FTest%20Audio%20CD%60s%2FIsoTek%20-%20Full%20System%20Enhancer%20%26%20Rejuvenation%20Disc%20Ape%2FIsoTek%20-%20Full%20System%20Enhancer%20%26%20Rejuvenation%20Disc.ape&metadata=false
Apr 17 16:34:56 volumio volumio[704]: info: URI /mnt/USB/Seagate_Expansion_Drive/Test Audio CD`s/IsoTek - Full System Enhancer & Rejuvenation Disc Ape/IsoTek - Full System Enhancer & Rejuvenation Disc.ape
Apr 17 16:34:58 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 17 16:34:58 volumio volumio[704]: info: CURURI: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape
Apr 17 16:34:58 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:34:58 volumio volumio[704]: info: Preloading song: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.ape
Apr 17 16:34:58 volumio volumio[704]: info: Exploding uri music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.ape in service mpd
Apr 17 16:34:58 volumio volumio[704]: info: ALBUMART /albumart?cacheid=877&web=//extralarge&path=%2Fmnt%2FUSB%2FSeagate_Expansion_Drive%2FTest%20Audio%20CD%60s%2FTriangle%20Demonstration%20CD%20Ape%2FCDImage.ape&metadata=false
Apr 17 16:34:58 volumio volumio[704]: info: URI /mnt/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.ape
Apr 17 16:35:01 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioReplaceandPlayItems
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::ClearQueue
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::stop
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::updateTrackBlock
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrackBlock
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::stPlaybackTimer
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::serviceStop
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 100
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::serviceStop
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::stop
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand stop
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::clearPlayQueue
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::saveQueue
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPushQueue
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::addQueueItems
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::addQueueItems
Apr 17 16:35:01 volumio volumio[704]: info: Preload queue cleared
Apr 17 16:35:01 volumio volumio[704]: info: Adding Item to queue: music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.cue
Apr 17 16:35:01 volumio volumio[704]: info: Exploding uri music-library/USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.cue in service mpd
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPushQueue
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::saveQueue
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::updateTrackBlock
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrackBlock
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPlay
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::play index 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::stop
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::play index undefined
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::setConsumeUpdateService undefined
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::startPlaybackTimer
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand stop
Apr 17 16:35:01 volumio volumio[704]: info:
Apr 17 16:35:01 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand stop took 106 milliseconds
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand stop took 5 milliseconds
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand clear
Apr 17 16:35:01 volumio volumio[704]: info:
Apr 17 16:35:01 volumio volumio[704]: ---------------------------- MPD announces system playlist update
Apr 17 16:35:01 volumio volumio[704]: info: Ignoring MPD Status Update
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand status took 4 milliseconds
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand clear took 3 milliseconds
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand load "USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.cue"
Apr 17 16:35:01 volumio volumio[704]: error: updateQueue error: null
Apr 17 16:35:01 volumio volumio[704]: info: ------------------------------ 2ms
Apr 17 16:35:01 volumio volumio[704]: info:
Apr 17 16:35:01 volumio volumio[704]: ---------------------------- MPD announces system playlist update
Apr 17 16:35:01 volumio volumio[704]: info: Ignoring MPD Status Update
Apr 17 16:35:01 volumio volumio[704]: error: ControllerMpd::pushError: Error: [2@0] {playlistinfo} Bad song index
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand load "USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.cue" took 4 milliseconds
Apr 17 16:35:01 volumio volumio[704]: info: ------------------------------ 8ms
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand play
Apr 17 16:35:01 volumio volumio[704]: info: ------------------------------ 3ms
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand play took 3 milliseconds
Apr 17 16:35:01 volumio volumio[704]: info:
Apr 17 16:35:01 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:35:01 volumio volumio[704]: info:
Apr 17 16:35:01 volumio volumio[704]: ---------------------------- MPD announces state update: player
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::getState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand status
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand status took 2 milliseconds
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand status took 1 milliseconds
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::parseState
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CDImage.ape","artist":null,"album":null,"uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.ape","trackType":"ape"}
Apr 17 16:35:01 volumio volumio[704]: verbose: CURRENT POSITION 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::syncState stateService play
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus stop
Apr 17 16:35:01 volumio volumio[704]: info: ------------------------------ 6ms
Apr 17 16:35:01 volumio volumio[704]: info: sendMpdCommand playlistinfo took 2 milliseconds
Apr 17 16:35:01 volumio volumio[704]: verbose: ControllerMpd::parseTrackInfo
Apr 17 16:35:01 volumio volumio[704]: info: ControllerMpd::pushState
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::servicePushState
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":301,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"CDImage.ape","artist":null,"album":null,"uri":"USB/Seagate_Expansion_Drive/Test Audio CD`s/Triangle Demonstration CD Ape/CDImage.ape","trackType":"ape"}
Apr 17 16:35:01 volumio volumio[704]: verbose: CURRENT POSITION 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::syncState stateService play
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::syncState currentStatus play
Apr 17 16:35:01 volumio volumio[704]: info: Received an update from plugin. extracting info from payload
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:35:01 volumio volumio[704]: info: CoreStateMachine::pushState
Apr 17 16:35:01 volumio volumio[704]: info: CorePlayQueue::getTrack 0
Apr 17 16:35:01 volumio volumio[704]: info: CoreCommandRouter::volumioPushState
Apr 17 16:35:01 volumio volumio[704]: info: ------------------------------ 13ms
Apr 17 16:35:01 volumio volumio[704]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title!
Apr 17 16:35:01 volumio volumio[704]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 17 16:35:01 volumio volumio[704]: TypeError: Cannot read property 'indexOf' of null
Apr 17 16:35:01 volumio volumio[704]: at ControllerLastFM.formatScrobbleData (/data/plugins/user_interface/lastfm/index.js:873:25)
Apr 17 16:35:01 volumio volumio[704]: at ControllerLastFM.checkStateUpdate (/data/plugins/user_interface/lastfm/index.js:825:26)
Apr 17 16:35:01 volumio volumio[704]: at Socket. (/data/plugins/user_interface/lastfm/index.js:110:52)
Apr 17 16:35:01 volumio volumio[704]: at Socket.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20)
Apr 17 16:35:01 volumio volumio[704]: at Socket.onevent (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:270:10)
Apr 17 16:35:01 volumio volumio[704]: at Socket.onpacket (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/socket.js:228:12)
Apr 17 16:35:01 volumio volumio[704]: at Manager. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15)
Apr 17 16:35:01 volumio volumio[704]: at Manager.Emitter.emit (/data/plugins/user_interface/lastfm/node_modules/component-emitter/index.js:133:20)
Apr 17 16:35:01 volumio volumio[704]: at Manager.ondecoded (/data/plugins/user_interface/lastfm/node_modules/socket.io-client/lib/manager.js:332:8)
Apr 17 16:35:01 volumio volumio[704]: at Decoder. (/data/plugins/user_interface/lastfm/node_modules/component-bind/index.js:21:15)
Apr 17 16:35:01 volumio volumio[704]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 17 16:35:01 volumio sudo[6516]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-17 16:34
Apr 17 16:35:01 volumio sudo[6516]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 10 (buster)"
NAME="Debian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:15:21 AM CET"
VOLUMIO_VERSION="3.629"
VOLUMIO_HARDWARE="tinkerboard"
VOLUMIO_DEVICENAME="Asus Tinkerboard"
VOLUMIO_HASH="293a767fd1b71cabc5f5be4916f770a0"