-- 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"