-- Logs begin at Fri 2026-04-03 20:23:46 JST, end at Fri 2026-04-03 22:32:18 JST. -- Apr 03 22:31:02 lucifer volumio[979]: verbose: New Socket.io Connection to 192.168.0.14 from 192.168.0.22 UA: Mozilla/5.0 (Linux; Android 14; SO-52C Build/65.2.B.2.259; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.164 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::volumioGetVisibleSources Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::volumioGetState Apr 03 22:31:02 lucifer volumio[979]: info: CorePlayQueue::getTrack 747 Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 03 22:31:02 lucifer volumio[979]: info: Received Get System Info Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 03 22:31:02 lucifer volumio[979]: info: Discovery: Getting this device information Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::volumioGetState Apr 03 22:31:02 lucifer volumio[979]: info: CorePlayQueue::getTrack 747 Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::volumioGetState Apr 03 22:31:02 lucifer volumio[979]: info: CorePlayQueue::getTrack 747 Apr 03 22:31:02 lucifer volumio[979]: info: Listing playlists Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::volumioGetQueue Apr 03 22:31:02 lucifer volumio[979]: info: CoreStateMachine::getQueue Apr 03 22:31:02 lucifer volumio[979]: info: CorePlayQueue::getQueue Apr 03 22:31:02 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 747 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 747 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.824+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.824+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/エルトン・ジョン/Elton John/01 Your Song.m4a" title="Your Song" Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand stop took 14 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand stop took 0 milliseconds Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: 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":"Your Song","artist":"エルトン・ジョン","album":"Elton John","uri":"NAS/disk1/iTunes/iTunes Media/Music/エルトン・ジョン/Elton John/01 Your Song.m4a","trackType":"m4a"} Apr 03 22:31:04 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: No code Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:04 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: No code Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.846+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.847+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.848+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.848+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.848+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.848+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.848+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand status took 12 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 12ms Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" took 11 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 0ms Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:04 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:04 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:04 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio[979]: info: No code Apr 03 22:31:04 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:04 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:04 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.854+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.855+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.855+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.855+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:04 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:04.855+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 17ms Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 10ms Apr 03 22:31:04 lucifer volumio[979]: info: sendMpdCommand play took 9 milliseconds Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 5ms Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 4ms Apr 03 22:31:04 lucifer volumio[979]: info: Apr 03 22:31:04 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:04 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:04 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: Apr 03 22:31:05 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand status took 7 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand status took 6 milliseconds Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:05 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:05 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.518+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.518+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.519+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.520+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 20ms Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 20ms Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 03 22:31:05 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:05 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:05 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:05 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":262,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"257 Kbps","isStreaming":false,"title":"Don't Let Me Be Lonely Tonight","artist":"SHANTI","album":"Romance with me","uri":"NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a","trackType":"m4a"} Apr 03 22:31:05 lucifer volumio[979]: verbose: CURRENT POSITION 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:05 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:05 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:05 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.528+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.528+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.528+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.528+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.528+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.529+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.529+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.529+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.529+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:05.530+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 29ms Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 27ms Apr 03 22:31:05 lucifer volumio[979]: info: ------------------------------ 26ms Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 603 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.428+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.428+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/SHANTI/Romance with me/01 Don't Let Me Be Lonely Tonight.m4a" title="Don't Let Me Be Lonely Tonight" Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand stop took 17 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand stop took 1 milliseconds Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: No code Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: No code Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.453+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.453+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.453+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.454+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" took 11 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 0ms Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:07 lucifer volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand play took 2 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 2ms Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:07 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 21 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 21 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: Apr 03 22:31:07 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:07 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":57,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:07 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 28ms Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.552+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=34 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.552+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.552+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=34 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.552+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.553+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=57 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.553+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=57 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.553+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.553+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 30ms Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 30ms Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 03 22:31:07 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:07 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:07 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":327,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"259 Kbps","isStreaming":false,"title":"cruise","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a","trackType":"m4a"} Apr 03 22:31:07 lucifer volumio[979]: verbose: CURRENT POSITION 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:07 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:07 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:07 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.559+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:07 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:07.560+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 17ms Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:07 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 540 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.658+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.658+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/11 cruise.m4a" title=cruise Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand stop took 20 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand stop took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: No code Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: No code Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.689+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.689+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.690+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.690+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.691+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.691+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.691+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.691+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.691+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 15ms Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 15ms Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" took 16 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:10 lucifer volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 17ms Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 4ms Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand play took 3 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:10 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 0ms Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 24 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 24 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 24 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: Apr 03 22:31:10 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:10 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:10 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 29ms Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=11 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=34 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=34 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.770+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 31ms Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 32ms Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:10 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:10 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:10 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":325,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"コルテオ ~行列~","artist":"Salyu","album":"MAIDEN VOYAGE","uri":"NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a","trackType":"m4a"} Apr 03 22:31:10 lucifer volumio[979]: verbose: CURRENT POSITION 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:10 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:10 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:10 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.777+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.777+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:10.780+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 19ms Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 18ms Apr 03 22:31:10 lucifer volumio[979]: info: ------------------------------ 18ms Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 533 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.108+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.108+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Salyu/MAIDEN VOYAGE/04 コルテオ ~行列~.m4a" title="コルテオ ~行列~" Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand stop took 17 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand stop took 0 milliseconds Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: No code Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: No code Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.134+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.134+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.134+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.135+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.135+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.135+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.135+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.136+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.136+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.136+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 12ms Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 12ms Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" took 12 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:13 lucifer volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 14ms Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:13 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 7ms Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 6ms Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand play took 6 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 5ms Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: Apr 03 22:31:13 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:13 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:13 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 10ms Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.283+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.284+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 03 22:31:13 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:13 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:13 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":176,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"262 Kbps","isStreaming":false,"title":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:13 lucifer volumio[979]: verbose: CURRENT POSITION 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:13 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:13 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:13 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.291+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.291+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.291+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.292+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.292+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.292+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:13 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:13.292+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 21ms Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 21ms Apr 03 22:31:13 lucifer volumio[979]: info: ------------------------------ 20ms Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 1179 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.180+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.181+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a" title=今更 Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand stop took 9 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand stop took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: 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":"今更","artist":"赤い公園","album":"公園デビュー","uri":"NAS/disk1/iTunes/iTunes Media/Music/赤い公園/公園デビュー/01 今更.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: No code Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: No code Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: No code Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.198+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.198+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.198+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.199+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.200+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.200+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 14ms Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 14ms Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" took 13 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:15 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand play took 3 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 3 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: Apr 03 22:31:15 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 5 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 7ms Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":536,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:15 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:15 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:15 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.269+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=536 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.270+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.271+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=536 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.271+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.272+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.272+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.272+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.272+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.273+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.273+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 20ms Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 03 22:31:15 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 15 milliseconds Apr 03 22:31:15 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:15 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":286,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"125 Kbps","isStreaming":false,"title":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:15 lucifer volumio[979]: verbose: CURRENT POSITION 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:15 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:15 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:15 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.280+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:15 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:15.281+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 22ms Apr 03 22:31:15 lucifer volumio[979]: info: ------------------------------ 22ms Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 809 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.285+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.285+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a" title="CHEERS FOR YOU" Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand stop took 18 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 3 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand stop took 3 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: 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":"CHEERS FOR YOU","artist":"中山美穂","album":"Perfect Best [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中山美穂/Perfect Best [Disc 2]/2-12 CHEERS FOR YOU.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: No code Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.309+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.310+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.310+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.310+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 10ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 8ms Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 7ms Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" took 7 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 2ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:17 lucifer volumio[979]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 9ms Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:17 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 2ms Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand play took 3 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 2ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 2ms Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 19 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 19 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: Apr 03 22:31:17 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 21ms Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:17 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":125,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:17 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":182,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:17 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.541+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=125 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.541+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=80 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.542+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=125 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.542+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.542+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.542+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=182 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.544+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.544+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=182 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.545+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 33ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 33ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 15ms Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 03 22:31:17 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":605,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:17 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":344,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:17 lucifer volumio[979]: verbose: CURRENT POSITION 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:17 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:17 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:17 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=605 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=605 volume=100 Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:17.551+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 19ms Apr 03 22:31:17 lucifer volumio[979]: info: ------------------------------ 19ms Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 834 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.261+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.261+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a" title="帰省 ~Never Forget~" Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand stop took 18 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand stop took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: 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":"帰省 ~Never Forget~","artist":"中森明菜","album":"オールタイム・ベスト -オリジナル- [Disc 2]","uri":"NAS/disk1/iTunes/iTunes Media/Music/中森明菜/オールタイム・ベスト -オリジナル- [Disc 2]/2-07 帰省 ~Never Forget~.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: No code Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: No code Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: No code Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.287+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=1 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.288+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 12ms Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 13ms Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" took 13 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:20 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 4ms Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand play took 3 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 22 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 22 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 23 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":582,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:20 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 27ms Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.384+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=582 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.384+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.384+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 27ms Apr 03 22:31:20 lucifer volumio[979]: info: Apr 03 22:31:20 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 4 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:20 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:20 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.389+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 33ms Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 03 22:31:20 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:20 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":406,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"112 Kbps","isStreaming":false,"title":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:20 lucifer volumio[979]: verbose: CURRENT POSITION 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:20 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:20 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:20 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:20 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:20.397+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 17ms Apr 03 22:31:20 lucifer volumio[979]: info: ------------------------------ 14ms Apr 03 22:31:28 lucifer volumio[979]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Eric%20Martin/Mr.%20Vocalist/571e872d-a2a9-4979-8f28-3c14336ec755.jpg' Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioNext Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::next Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::stPlaybackTimer Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::serviceStop Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 70 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::serviceStop Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::stop Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.408+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.408+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a" title="Night Flower" Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand stop took 15 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::play index undefined Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::startPlaybackTimer Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::clearAddPlayTracks NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::updateTrackBlock Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrackBlock Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand stop took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand clear Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand clear took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: 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":"Night Flower","artist":"Donald Byrd Feat. Herbie Hancock","album":"Out Of The Blue","uri":"NAS/disk1/iTunes/iTunes Media/Music/Compilations/Out Of The Blue/1-13 Night Flower.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: No code Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: No code Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: No code Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.433+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.434+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.434+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.434+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.435+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.435+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.435+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_STOPPED positionMs=0 volume=100 Apr 03 22:31:30 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:30.436+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 18ms Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 15ms Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: error: updateQueue error: null Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand add "NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" took 15 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 1ms Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand play Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces system playlist update Apr 03 22:31:30 lucifer volumio[979]: info: Ignoring MPD Status Update Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 4ms Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand play took 4 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 4ms Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 3ms Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 8 milliseconds Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: Apr 03 22:31:30 lucifer volumio[979]: ---------------------------- MPD announces state update: player Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::getState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand status Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 9 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 9 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 0 milliseconds Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus stop Apr 03 22:31:30 lucifer volumio[979]: info: ------------------------------ 11ms Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand status took 2 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseState Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:30 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:30 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:30 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:30 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:30 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:30 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:30 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:30 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:30 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.000+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=91 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.000+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=251 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=251 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.000+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=91 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.001+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio[979]: info: ------------------------------ 22ms Apr 03 22:31:31 lucifer volumio[979]: info: ------------------------------ 22ms Apr 03 22:31:31 lucifer volumio[979]: info: ------------------------------ 16ms Apr 03 22:31:31 lucifer volumio[979]: info: ------------------------------ 15ms Apr 03 22:31:31 lucifer volumio[979]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 03 22:31:31 lucifer volumio[979]: verbose: ControllerMpd::parseTrackInfo Apr 03 22:31:31 lucifer volumio[979]: info: ControllerMpd::pushState Apr 03 22:31:31 lucifer volumio[979]: info: CoreCommandRouter::servicePushState Apr 03 22:31:31 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:31 lucifer volumio[979]: verbose: STATE SERVICE {"status":"play","position":0,"seek":856,"duration":380,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"261 Kbps","isStreaming":false,"title":"Nature Boy","artist":"土岐麻子","album":"STANDARDS on the sofa ~土岐麻子ジャズを歌う~","uri":"NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a","trackType":"m4a"} Apr 03 22:31:31 lucifer volumio[979]: verbose: CURRENT POSITION 884 Apr 03 22:31:31 lucifer volumio[979]: info: CoreStateMachine::syncState stateService play Apr 03 22:31:31 lucifer volumio[979]: info: CoreStateMachine::syncState currentStatus play Apr 03 22:31:31 lucifer volumio[979]: info: Received an update from plugin. extracting info from payload Apr 03 22:31:31 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:31 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:31 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:31 lucifer volumio[979]: info: CoreStateMachine::pushState Apr 03 22:31:31 lucifer volumio[979]: info: CorePlayQueue::getTrack 884 Apr 03 22:31:31 lucifer volumio[979]: info: CoreCommandRouter::volumioPushState Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.009+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.010+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" state=STATUS_PLAYING positionMs=856 volume=100 Apr 03 22:31:31 lucifer volumio5-onboarding[1507]: time=2026-04-03T22:31:31.010+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.22:56336,00:00:00:00:00:00%0a @ 0x35726f0" id="music-library/NAS/disk1/iTunes/iTunes Media/Music/土岐麻子/STANDARDS on the sofa ~土岐麻子ジャズを歌う~/05 Nature Boy.m4a" title="Nature Boy" Apr 03 22:31:31 lucifer volumio[979]: info: ------------------------------ 19ms Apr 03 22:31:43 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 03 22:31:43 lucifer volumio[979]: info: CURURI: genres://Country%20%26%20Folk Apr 03 22:31:43 lucifer volumio[979]: info: Preload queue cleared Apr 03 22:31:43 lucifer volumio[979]: info: Preload queue cleared Apr 03 22:31:54 lucifer volumio[979]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 03 22:31:54 lucifer volumio[979]: info: CURURI: artists:// Apr 03 22:31:54 lucifer volumio[979]: info: Preload queue cleared Apr 03 22:32:17 lucifer volumio[979]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 22:32:17 lucifer volumio[979]: TypeError: Cannot read property 'slice' of null Apr 03 22:32:17 lucifer volumio[979]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Apr 03 22:32:17 lucifer volumio[979]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Apr 03 22:32:17 lucifer volumio[979]: at Object.onceWrapper (events.js:422:26) Apr 03 22:32:17 lucifer volumio[979]: at ClientRequest.emit (events.js:315:20) Apr 03 22:32:17 lucifer volumio[979]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:641:27) Apr 03 22:32:17 lucifer volumio[979]: at HTTPParser.parserOnHeadersComplete (_http_common.js:126:17) Apr 03 22:32:17 lucifer volumio[979]: at HTTPParser.execute () Apr 03 22:32:17 lucifer volumio[979]: at TLSSocket.socketOnData (_http_client.js:509:22) Apr 03 22:32:17 lucifer volumio[979]: at TLSSocket.emit (events.js:315:20) Apr 03 22:32:17 lucifer volumio[979]: at addChunk (internal/streams/readable.js:309:12) Apr 03 22:32:17 lucifer volumio[979]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 22:32:18 lucifer sudo[17997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-03 22:31 Apr 03 22:32:18 lucifer sudo[17997]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"