-- Logs begin at Sun 2025-04-20 18:08:19 CEST, end at Sun 2025-04-20 18:10:55 CEST. -- Apr 20 18:09:00 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:00 volumio volumio[1202]: info: Listing playlists Apr 20 18:09:00 volumio volumio[1510]: ......................................................................................................++++ Apr 20 18:09:00 volumio volumio[1510]: e is 65537 (0x010001) Apr 20 18:09:00 volumio volumio[1510]: writing RSA key Apr 20 18:09:00 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:09:00 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:09:00 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:00 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:00 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:09:00 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:00 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:09:00 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:09:00 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:00 volumio volumio[1202]: info: [1745165340700] ControllerWebradio::clearAddPlayTrack Apr 20 18:09:00 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:00 volumio volumio[1202]: info: sendMpdCommand stop took 1 milliseconds Apr 20 18:09:00 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:09:00 volumio volumio[1202]: info: Apr 20 18:09:00 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:00 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:00 volumio volumio[1202]: info: sendMpdCommand clear took 0 milliseconds Apr 20 18:09:00 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:00 volumio volumio[1202]: info: Apr 20 18:09:00 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:00 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:00 volumio volumio[1202]: info: Apr 20 18:09:00 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:00 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:00 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:00 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:03 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:03 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:03 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:03 volumio volumio[1202]: info: ------------------------------ 2327ms Apr 20 18:09:03 volumio volumio[1202]: info: ------------------------------ 2327ms Apr 20 18:09:03 volumio volumio[1202]: info: Apr 20 18:09:03 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:03 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:03 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 2 milliseconds Apr 20 18:09:03 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:09:03 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:09:03 volumio volumio[1202]: info: Apr 20 18:09:03 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:03 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:03 volumio volumio[1202]: info: Apr 20 18:09:03 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:03 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:03 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:03 volumio volumio[1202]: info: sendMpdCommand play took 1 milliseconds Apr 20 18:09:03 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:03 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:04 volumio volumio[1202]: info: Apr 20 18:09:04 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:04 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:04 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:04 volumio volumio[1202]: info: Apr 20 18:09:04 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:04 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:04 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:04 volumio volumio[1202]: info: Apr 20 18:09:04 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:04 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:04 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 29 milliseconds Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:05 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 29 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 29 milliseconds Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:05 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:05 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:05 volumio volumio[1202]: info: Apr 20 18:09:05 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 2 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus stop Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:05 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:05 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 40ms Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 49ms Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 49ms Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 20 18:09:05 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:05 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:05 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:05 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:05 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:05 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:05 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:05 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 39ms Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 38ms Apr 20 18:09:05 volumio volumio[1202]: info: ------------------------------ 38ms Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] Togle GPIO: ON Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 20 18:09:05 volumio volumio[1202]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 20 18:09:05 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:05 volumio volumio[1202]: info: BOOT COMPLETED Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::volumioStop Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::stop Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::stPlaybackTimer Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::updateTrackBlock Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrackBlock Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::serviceStop Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::serviceStop Apr 20 18:09:09 volumio volumio[1202]: info: [1745165349092] ControllerWebradio::stop Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:09:09 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand stop took 14 milliseconds Apr 20 18:09:09 volumio volumio[1202]: info: Apr 20 18:09:09 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:09 volumio volumio[1202]: info: Apr 20 18:09:09 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:09 volumio volumio[1202]: info: Apr 20 18:09:09 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand status took 0 milliseconds Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 20 18:09:09 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 0 milliseconds Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:09 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:09 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:09 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:09 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:09 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:09 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:09 volumio volumio[1202]: info: ------------------------------ 17ms Apr 20 18:09:09 volumio volumio[1202]: info: ------------------------------ 18ms Apr 20 18:09:09 volumio volumio[1202]: info: ------------------------------ 17ms Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:09:09 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:09 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:09 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:09 volumio volumio[1202]: info: [ASDebug] Togle GPIO: OFF Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 20 18:09:09 volumio volumio-remote-updater[729]: No test mode Apr 20 18:09:09 volumio volumio-remote-updater[729]: No alpha test mode Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 20 18:09:09 volumio volumio[1202]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 20 18:09:09 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 20 18:09:10 volumio systemd[1]: systemd-timedated.service: Succeeded. Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:10 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::volumioGetBrowseSources Apr 20 18:09:10 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 20 18:09:10 volumio go-librespot[1406]: time="2025-04-20T18:09:10+02:00" level=trace msg="sent dealer ping" Apr 20 18:09:10 volumio go-librespot[1406]: time="2025-04-20T18:09:10+02:00" level=trace msg="received dealer pong" Apr 20 18:09:13 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 20 18:09:13 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 20 18:09:17 volumio volumio[1202]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] Setting UI defaults Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] Port: 5 Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] Inverted: false Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] Latched: false Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] On pulse width: 500 Apr 20 18:09:17 volumio volumio[1202]: info: [ASDebug] Off pulse width: 500 Apr 20 18:09:20 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:20 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:20 volumio volumio[1202]: info: Listing playlists Apr 20 18:09:20 volumio volumio[1202]: info: Listing playlists Apr 20 18:09:22 volumio volumio[1202]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Apr 20 18:09:22 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: Port: 5 Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: Inverted: true Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: Delay: 100 Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: Latched: false Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: On Pulse width: 500 Apr 20 18:09:22 volumio volumio[1202]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Apr 20 18:09:24 volumio ntpd[954]: Soliciting pool server 212.51.144.46 Apr 20 18:09:25 volumio ntpd[954]: Soliciting pool server 156.106.214.52 Apr 20 18:09:26 volumio ntpd[954]: Soliciting pool server 62.220.129.71 Apr 20 18:09:27 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:09:27 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:09:27 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:27 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:27 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:09:27 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:27 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:09:27 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:09:27 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:27 volumio volumio[1202]: info: [1745165367242] ControllerWebradio::clearAddPlayTrack Apr 20 18:09:27 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:27 volumio volumio[1202]: info: sendMpdCommand stop took 1 milliseconds Apr 20 18:09:27 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:09:27 volumio volumio[1202]: info: Apr 20 18:09:27 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:27 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:27 volumio volumio[1202]: info: sendMpdCommand clear took 0 milliseconds Apr 20 18:09:27 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:27 volumio volumio[1202]: info: Apr 20 18:09:27 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:27 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:27 volumio volumio[1202]: info: Apr 20 18:09:27 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:27 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:27 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:27 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:27 volumio ntpd[954]: Soliciting pool server 82.197.162.18 Apr 20 18:09:27 volumio ntpd[954]: Soliciting pool server 192.33.214.57 Apr 20 18:09:27 volumio ntpd[954]: Soliciting pool server 195.186.1.101 Apr 20 18:09:28 volumio ntpd[954]: Soliciting pool server 217.147.223.78 Apr 20 18:09:28 volumio ntpd[954]: Soliciting pool server 130.60.164.150 Apr 20 18:09:28 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:09:28 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:09:28 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:28 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:28 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:09:28 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:28 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:09:28 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:09:28 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:28 volumio volumio[1202]: info: [1745165368875] ControllerWebradio::clearAddPlayTrack Apr 20 18:09:28 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:29 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:29 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:29 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:29 volumio volumio[1202]: info: ------------------------------ 1924ms Apr 20 18:09:29 volumio volumio[1202]: info: ------------------------------ 1924ms Apr 20 18:09:29 volumio volumio[1202]: info: sendMpdCommand stop took 293 milliseconds Apr 20 18:09:29 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:09:29 volumio volumio[1202]: info: Apr 20 18:09:29 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:29 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:29 volumio volumio[1202]: info: Apr 20 18:09:29 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:29 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:29 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 1 milliseconds Apr 20 18:09:29 volumio volumio[1202]: info: sendMpdCommand clear took 1 milliseconds Apr 20 18:09:29 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:09:29 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:09:29 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:29 volumio volumio[1202]: info: Apr 20 18:09:29 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:29 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:29 volumio volumio[1202]: info: Apr 20 18:09:29 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:29 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:29 volumio ntpd[954]: Soliciting pool server 81.94.123.16 Apr 20 18:09:29 volumio ntpd[954]: Soliciting pool server 91.235.212.22 Apr 20 18:09:29 volumio ntpd[954]: Soliciting pool server 195.186.4.101 Apr 20 18:09:30 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:30 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:09:30 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:09:30 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:30 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:30 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:09:30 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:30 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:09:30 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:09:30 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:30 volumio volumio[1202]: info: [1745165370594] ControllerWebradio::clearAddPlayTrack Apr 20 18:09:30 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:30 volumio ntpd[954]: Soliciting pool server 156.106.214.48 Apr 20 18:09:30 volumio ntpd[954]: Soliciting pool server 81.6.2.165 Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2111ms Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2111ms Apr 20 18:09:31 volumio volumio[1202]: info: sendMpdCommand play took 2111 milliseconds Apr 20 18:09:31 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2111ms Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2110ms Apr 20 18:09:31 volumio volumio[1202]: info: sendMpdCommand stop took 686 milliseconds Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:31 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 1 milliseconds Apr 20 18:09:31 volumio volumio[1202]: info: sendMpdCommand clear took 2 milliseconds Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:31 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:09:31 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:09:31 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:31 volumio volumio[1202]: Upnp client error: Error: This socket has been ended by the other party Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: info: Apr 20 18:09:31 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:31 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:31 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:31 volumio volumio[1202]: info: sendMpdCommand play took 1 milliseconds Apr 20 18:09:31 volumio ntpd[954]: Soliciting pool server 62.12.167.109 Apr 20 18:09:32 volumio ntpd[954]: Soliciting pool server 109.233.182.115 Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:33 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:33 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 1888ms Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 1888ms Apr 20 18:09:33 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 0 milliseconds Apr 20 18:09:33 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:33 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:33 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 3ms Apr 20 18:09:33 volumio volumio[1202]: info: sendMpdCommand play took 3 milliseconds Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:09:33 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:09:33 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:09:33 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:33 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:09:33 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:09:33 volumio volumio[1202]: info: [1745165373402] ControllerWebradio::clearAddPlayTrack Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:09:33 volumio volumio[1202]: info: sendMpdCommand stop took 3 milliseconds Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:33 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:33 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:33 volumio volumio[1202]: info: sendMpdCommand clear took 0 milliseconds Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:33 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:33 volumio volumio[1202]: info: Apr 20 18:09:33 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:33 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:33 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:09:33 volumio volumio[1202]: info: sendMpdCommand status took 2 milliseconds Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:09:33 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:33 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:33 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:33 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:33 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:33 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:33 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:33 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:33 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:33 volumio volumio[1202]: info: ------------------------------ 9ms Apr 20 18:09:33 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: stop Apr 20 18:09:33 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:33 volumio ntpd[954]: Soliciting pool server 2a02:418:3008:5e37::434 Apr 20 18:09:35 volumio ntpd[954]: receive: Unexpected origin timestamp 0xebaf9abe.dea1d73d does not match aorg 0000000000.00000000 from server@81.94.123.16 xmt 0xebaf9abf.2f4d1a9a Apr 20 18:09:35 volumio ntpd[954]: receive: Unexpected origin timestamp 0xebaf9abe.dea0f17e does not match aorg 0000000000.00000000 from server@91.235.212.22 xmt 0xebaf9abf.2f6a06fe Apr 20 18:09:35 volumio ntpd[954]: receive: Unexpected origin timestamp 0xebaf9abe.dea3c629 does not match aorg 0000000000.00000000 from server@82.197.162.18 xmt 0xebaf9abf.2f8a7be2 Apr 20 18:09:35 volumio ntpd[954]: receive: Unexpected origin timestamp 0xebaf9abe.dea53919 does not match aorg 0000000000.00000000 from server@156.106.214.52 xmt 0xebaf9abf.2f26a7d5 Apr 20 18:09:35 volumio ntpd[954]: receive: Unexpected origin timestamp 0xebaf9abe.de9da7d7 does not match aorg 0000000000.00000000 from server@81.6.2.165 xmt 0xebaf9abf.301569b6 Apr 20 18:09:35 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:09:35 volumio volumio[1202]: info: sendMpdCommand status took 2181 milliseconds Apr 20 18:09:35 volumio volumio[1202]: info: sendMpdCommand status took 2180 milliseconds Apr 20 18:09:35 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:35 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:35 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:35 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:35 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:35 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:09:35 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:35 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:35 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:35 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:35 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:35 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:35 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:35 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:35 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:35 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:35 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 2198ms Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 2197ms Apr 20 18:09:35 volumio volumio[1202]: info: Apr 20 18:09:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:35 volumio volumio[1202]: info: Apr 20 18:09:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:35 volumio volumio[1202]: info: Apr 20 18:09:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:35 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 17 milliseconds Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:09:35 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:09:35 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:09:35 volumio volumio[1202]: info: Apr 20 18:09:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:35 volumio volumio[1202]: info: Apr 20 18:09:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:35 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: stop Apr 20 18:09:35 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: stop Apr 20 18:09:35 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:35 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 7ms Apr 20 18:09:35 volumio volumio[1202]: info: sendMpdCommand play took 6 milliseconds Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 6ms Apr 20 18:09:35 volumio volumio[1202]: info: ------------------------------ 6ms Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:38 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 26 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 27 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 26 milliseconds Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:38 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:09:38 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:09:38 volumio volumio[1202]: info: Apr 20 18:09:38 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 3ms Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 2 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 3ms Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 3 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 3ms Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand status took 3 milliseconds Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus stop Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":80,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:38 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:38 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 40ms Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 57ms Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 57ms Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 20 18:09:38 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 27 milliseconds Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:38 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:38 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:09:38 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:09:38 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:09:38 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:09:38 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:09:38 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:09:38 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 58ms Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 56ms Apr 20 18:09:38 volumio volumio[1202]: info: ------------------------------ 56ms Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: stop Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] Togle GPIO: ON Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:38 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:09:40 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:09:40 volumio volumio[1202]: info: Listing playlists Apr 20 18:09:40 volumio volumio[1202]: info: Listing playlists Apr 20 18:09:41 volumio go-librespot[1406]: time="2025-04-20T18:09:41+02:00" level=trace msg="sent dealer ping" Apr 20 18:09:41 volumio go-librespot[1406]: time="2025-04-20T18:09:41+02:00" level=trace msg="received dealer pong" Apr 20 18:09:50 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:00 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:00 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:00 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:02 volumio volumio[1202]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Apr 20 18:10:02 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: Port: 5 Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: Inverted: false Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: Delay: 100 Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: Latched: false Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: On Pulse width: 500 Apr 20 18:10:02 volumio volumio[1202]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::volumioStop Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::stop Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::stPlaybackTimer Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::updateTrackBlock Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrackBlock Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::serviceStop Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::serviceStop Apr 20 18:10:06 volumio volumio[1202]: info: [1745165406351] ControllerWebradio::stop Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:10:06 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:06 volumio volumio[1202]: info: Apr 20 18:10:06 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand stop took 16 milliseconds Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand status took 0 milliseconds Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:06 volumio volumio[1202]: info: Apr 20 18:10:06 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:06 volumio volumio[1202]: info: Apr 20 18:10:06 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand status took 0 milliseconds Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand status took 0 milliseconds Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:10:06 volumio volumio[1202]: info: ------------------------------ 12ms Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 20 18:10:06 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:06 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:10:06 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:06 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:06 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:06 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:06 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 20 18:10:06 volumio volumio[1202]: info: ------------------------------ 21ms Apr 20 18:10:06 volumio volumio[1202]: info: ------------------------------ 20ms Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: play Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Apr 20 18:10:06 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:06 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:06 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:06 volumio volumio[1202]: info: [ASDebug] Togle GPIO: OFF Apr 20 18:10:10 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:10 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:11 volumio go-librespot[1406]: time="2025-04-20T18:10:11+02:00" level=trace msg="sent dealer ping" Apr 20 18:10:11 volumio go-librespot[1406]: time="2025-04-20T18:10:11+02:00" level=trace msg="received dealer pong" Apr 20 18:10:12 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 20 18:10:12 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 20 18:10:16 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 20 18:10:16 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 20 18:10:20 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:20 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:20 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:20 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:30 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:30 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:33 volumio volumio[1202]: info: Enabling plugin peppymeterbasic Apr 20 18:10:33 volumio volumio[1202]: info: Loading plugin "peppymeterbasic"... Apr 20 18:10:33 volumio volumio[1202]: info: Preparing to generate the ALSA configuration file Apr 20 18:10:33 volumio volumio[1202]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 20 18:10:33 volumio volumio[1202]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Apr 20 18:10:33 volumio volumio[1202]: info: Reading ALSA contributions from plugins. Apr 20 18:10:33 volumio volumio[1202]: info: Asound.conf file written Apr 20 18:10:33 volumio sudo[2240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Apr 20 18:10:33 volumio sudo[2240]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio sudo[2240]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: xcb_connection_has_error() returned true Apr 20 18:10:33 volumio volumio[1202]: info: Output device has changed, restarting MPD Apr 20 18:10:33 volumio sudo[2245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 20 18:10:33 volumio sudo[2245]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio sudo[2245]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: info: Output device has changed, restarting Shairport Sync Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 18:10:33 volumio sudo[2248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 20 18:10:33 volumio sudo[2248]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio systemd[1]: Stopping Music Player Daemon... Apr 20 18:10:33 volumio volumio[1202]: xcb_connection_has_error() returned true Apr 20 18:10:33 volumio volumio[1202]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 20 18:10:33 volumio volumio[1202]: xcb_connection_has_error() returned true Apr 20 18:10:33 volumio volumio[1202]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio systemd[1]: mpd.service: Succeeded. Apr 20 18:10:33 volumio systemd[1]: Stopped Music Player Daemon. Apr 20 18:10:33 volumio vtcs[1739]: [2025-04-20 18:10:33.485] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Apr 20 18:10:33 volumio vtcs[1739]: [2025-04-20 18:10:33.485] [tisoc] [error] [SpkconServer.cpp:472] socket write error. fd=3 errorno=32 error=Broken pipe Apr 20 18:10:33 volumio vtcs[1739]: [2025-04-20 18:10:33.485] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Apr 20 18:10:33 volumio systemd[1]: Starting Music Player Daemon... Apr 20 18:10:33 volumio sudo[2257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 20 18:10:33 volumio volumio[1202]: info: PLUGIN START: peppymeterbasic Apr 20 18:10:33 volumio sudo[2257]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 20 18:10:33 volumio volumio[1202]: info: Preparing to generate the ALSA configuration file Apr 20 18:10:33 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Apr 20 18:10:33 volumio volumio[1202]: info: Done. Apr 20 18:10:33 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Apr 20 18:10:33 volumio systemd[1]: vtcs.service: Succeeded. Apr 20 18:10:33 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Apr 20 18:10:33 volumio sudo[2257]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 20 18:10:33 volumio volumio[1202]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Apr 20 18:10:33 volumio volumio[1202]: info: Reading ALSA contributions from plugins. Apr 20 18:10:33 volumio sudo[2253]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 20 18:10:33 volumio sudo[2253]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio sudo[2253]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio sudo[2261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 20 18:10:33 volumio sudo[2261]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio volumio[1202]: info: MPD Permissions set Apr 20 18:10:33 volumio sudo[2261]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: Starting Shairport Sync Apr 20 18:10:33 volumio sudo[2271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 20 18:10:33 volumio sudo[2271]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio volumio[1202]: info: Asound.conf file unchanged, so no further update is needed Apr 20 18:10:33 volumio volumio[1202]: info: Output device has changed, restarting MPD Apr 20 18:10:33 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 20 18:10:33 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 20 18:10:33 volumio sudo[2274]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 20 18:10:33 volumio sudo[2274]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 20 18:10:33 volumio sudo[2274]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: info: Output device has changed, restarting Shairport Sync Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 18:10:33 volumio sudo[2278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 20 18:10:33 volumio sudo[2278]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 20 18:10:33 volumio sudo[2271]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: xcb_connection_has_error() returned true Apr 20 18:10:33 volumio volumio[1202]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 20 18:10:33 volumio volumio[1202]: xcb_connection_has_error() returned true Apr 20 18:10:33 volumio volumio[1202]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 20 18:10:33 volumio systemd[1]: mpd.service: Succeeded. Apr 20 18:10:33 volumio systemd[1]: Stopped Music Player Daemon. Apr 20 18:10:33 volumio systemd[1]: Starting Music Player Daemon... Apr 20 18:10:33 volumio sudo[2289]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 20 18:10:33 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio sudo[2285]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 20 18:10:33 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio sudo[2298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 20 18:10:33 volumio sudo[2298]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio sudo[2298]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: info: MPD Permissions set Apr 20 18:10:33 volumio volumio[1202]: info: Shairport-Sync Started Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 18:10:33 volumio volumio[1202]: info: Starting Shairport Sync Apr 20 18:10:33 volumio sudo[2306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 20 18:10:33 volumio sudo[2306]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:33 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:33 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 20 18:10:33 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 20 18:10:33 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:33 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 20 18:10:33 volumio sudo[2306]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: info: Shairport-Sync Started Apr 20 18:10:33 volumio mpd[2294]: Apr 20 18:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 20 18:10:33 volumio systemd[1]: Started Music Player Daemon. Apr 20 18:10:33 volumio sudo[2278]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio sudo[2248]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:33 volumio volumio[1202]: error: MPD error: The expression evaluated to a falsy value: Apr 20 18:10:33 volumio volumio[1202]: assert.ok(self.idling) Apr 20 18:10:33 volumio volumio[1202]: error: The expression evaluated to a falsy value: Apr 20 18:10:33 volumio volumio[1202]: assert.ok(self.idling) Apr 20 18:10:33 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:10:33 volumio volumio[1202]: error: Upnp client error: Error: This socket has been ended by the other party Apr 20 18:10:35 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:10:35 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:10:35 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:10:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:35 volumio volumio[1202]: info: CoreStateMachine::startPlaybackTimer Apr 20 18:10:35 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:35 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:10:35 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:10:35 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 20 18:10:35 volumio volumio[1202]: info: [1745165435586] ControllerWebradio::clearAddPlayTrack Apr 20 18:10:35 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand stop Apr 20 18:10:35 volumio volumio[1202]: info: sendMpdCommand stop took 0 milliseconds Apr 20 18:10:35 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand clear Apr 20 18:10:35 volumio volumio[1202]: info: Apr 20 18:10:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:35 volumio volumio[1202]: info: sendMpdCommand clear took 1 milliseconds Apr 20 18:10:35 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand load "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:10:35 volumio volumio[1202]: info: Apr 20 18:10:35 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:35 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:35 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:10:35 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:10:36 volumio volumio[1202]: info: TidalConnect service stoped! Apr 20 18:10:36 volumio volumio[1202]: info: TidalConnect service stoped! Apr 20 18:10:36 volumio volumio[1202]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 20 18:10:36 volumio volumio[1202]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 20 18:10:36 volumio sudo[2323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 20 18:10:36 volumio sudo[2323]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:36 volumio systemd[1]: Started Volumio Tidal Connect Service. Apr 20 18:10:36 volumio sudo[2323]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:36 volumio volumio[1202]: info: TidalConnect service stoped! Apr 20 18:10:36 volumio volumio[1202]: info: TidalConnect service stoped! Apr 20 18:10:36 volumio volumio[1202]: info: Executing endpoint tc_getconfig Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 20 18:10:36 volumio vtcs[2325]: STARTING TidalConnect services, version: 1.5.0.45 Apr 20 18:10:36 volumio volumio[1202]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 20 18:10:36 volumio volumio[1202]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 20 18:10:36 volumio vtcs[2325]: STARTED TidalConnect services. Apr 20 18:10:36 volumio volumio[1202]: info: Executing endpoint tc_connect Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 20 18:10:36 volumio volumio[1202]: info: Connecting to TidalConnect Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:36 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:36 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:36 volumio sudo[2345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 20 18:10:36 volumio sudo[2345]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:36 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:36 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:36 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:36 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:36 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:36 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:36 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:36 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:36 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:36 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:36 volumio volumio[1202]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Apr 20 18:10:36 volumio sudo[2345]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:36 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: stop Apr 20 18:10:36 volumio volumio[1202]: info: [ASDebug] CurState: stop PrevState: stop Apr 20 18:10:36 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:36 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:36 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status stop Apr 20 18:10:36 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status stop Apr 20 18:10:36 volumio sudo[2357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Apr 20 18:10:36 volumio sudo[2357]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:36 volumio sudo[2360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Apr 20 18:10:36 volumio sudo[2360]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:36 volumio sudo[2357]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:36 volumio sudo[2360]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:36 volumio volumio[1202]: info: peppymeterbasic Daemon Stop Apr 20 18:10:36 volumio volumio[1202]: info: peppymeterbasic Daemon Stop Apr 20 18:10:37 volumio volumio[1202]: info: Enabling plugin touch_display Apr 20 18:10:37 volumio volumio[1202]: info: Loading plugin "touch_display"... Apr 20 18:10:37 volumio volumio[1202]: info: Applying required configuration parameters for plugin touch_display Apr 20 18:10:37 volumio volumio[1202]: info: PLUGIN START: touch_display Apr 20 18:10:37 volumio volumio[1202]: info: Loading i18n strings for locale fr Apr 20 18:10:37 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 20 18:10:37 volumio sudo[2363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Apr 20 18:10:37 volumio sudo[2363]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:37 volumio sudo[2366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Apr 20 18:10:37 volumio sudo[2366]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:37 volumio systemd[1]: Stopping Getty on tty1... Apr 20 18:10:37 volumio systemd[1]: getty@tty1.service: Main process exited, code=killed, status=15/TERM Apr 20 18:10:37 volumio systemd[1]: getty@tty1.service: Succeeded. Apr 20 18:10:37 volumio systemd[1]: Stopped Getty on tty1. Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: No backlight interface detected. Apr 20 18:10:37 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: running Apr 20 18:10:37 volumio sudo[2369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Apr 20 18:10:37 volumio sudo[2363]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:37 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:37 volumio systemd[1]: Reloading. Apr 20 18:10:37 volumio volumio[1202]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: systemctl stop getty@tty1.service succeeded. Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Apr 20 18:10:37 volumio sudo[2385]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Apr 20 18:10:37 volumio sudo[2385]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:37 volumio sudo[2388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Apr 20 18:10:37 volumio sudo[2388]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:37 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 20 18:10:37 volumio sudo[2385]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:37 volumio sudo[2388]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Apr 20 18:10:37 volumio volumio[1202]: info: touch_display: Rotation settings written to /etc/X11/xorg.conf.d/95-touch_display-plugin.conf. Apr 20 18:10:37 volumio systemd[1]: serial-getty@ttyAMA10.service: Current command vanished from the unit file, execution of the command list won't be resumed. Apr 20 18:10:37 volumio sudo[2366]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:37 volumio systemd[1]: Reloading. Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: systemctl disable getty@tty1.service succeeded. Apr 20 18:10:38 volumio volumio[1202]: error: updateQueue error: null Apr 20 18:10:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" Apr 20 18:10:38 volumio volumio[1202]: info: ------------------------------ 2457ms Apr 20 18:10:38 volumio volumio[1202]: Upnp client error: Error: This socket has been ended by the other party Apr 20 18:10:38 volumio volumio[1202]: info: Apr 20 18:10:38 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:38 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:38 volumio volumio[1202]: info: sendMpdCommand add "https://listen-msmn.sharp-stream.com/nme2.mp3" took 1 milliseconds Apr 20 18:10:38 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 20 18:10:38 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand play Apr 20 18:10:38 volumio volumio[1202]: info: Apr 20 18:10:38 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:38 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:38 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:10:38 volumio volumio[1202]: info: sendMpdCommand play took 1 milliseconds Apr 20 18:10:38 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:10:38 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Apr 20 18:10:38 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: systemctl daemon-reload succeeded. Apr 20 18:10:38 volumio sudo[2406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Apr 20 18:10:38 volumio sudo[2406]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:38 volumio systemd[1]: Started Volumio Kiosk. Apr 20 18:10:38 volumio sudo[2406]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: Volumio Kiosk started. Apr 20 18:10:38 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:38 volumio volumio[1202]: info: Done. Apr 20 18:10:38 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: X display number found: Apr 20 18:10:38 volumio startx[2408]: X.Org X Server 1.20.4 Apr 20 18:10:38 volumio startx[2408]: X Protocol Version 11, Revision 0 Apr 20 18:10:38 volumio startx[2408]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Apr 20 18:10:38 volumio startx[2408]: Current Operating System: Linux volumio 6.6.62-v8+ #1816 SMP PREEMPT Mon Nov 18 15:35:52 GMT 2024 aarch64 Apr 20 18:10:38 volumio startx[2408]: Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe cgroup_disable=memory numa_policy=interleave numa=fake=8 system_heap.max_order=0 smsc95xx.macaddr=2C:CF:67:BF:71:2C vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyAMA10,115200 console=tty1 imgpart=UUID=2943a0f6-9461-45b8-a7ba-934000b22bce imgfile=/volumio_current.sqsh bootpart=UUID=447A-6E39 datapart=UUID=82c06758-becd-4058-b472-72831fcbd146 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Apr 20 18:10:38 volumio startx[2408]: Build Date: 04 April 2023 07:50:56AM Apr 20 18:10:38 volumio startx[2408]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Apr 20 18:10:38 volumio startx[2408]: Current version of pixman: 0.36.0 Apr 20 18:10:38 volumio startx[2408]: Before reporting problems, check http://wiki.x.org Apr 20 18:10:38 volumio startx[2408]: to make sure that you have the latest version. Apr 20 18:10:38 volumio startx[2408]: Markers: (--) probed, (**) from config file, (==) default setting, Apr 20 18:10:38 volumio startx[2408]: (++) from command line, (!!) notice, (II) informational, Apr 20 18:10:38 volumio startx[2408]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Apr 20 18:10:38 volumio startx[2408]: (==) Log file: "/var/log/Xorg.0.log", Time: Sun Apr 20 18:10:38 2025 Apr 20 18:10:38 volumio startx[2408]: (==) Using config directory: "/etc/X11/xorg.conf.d" Apr 20 18:10:38 volumio startx[2408]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: X display number found: 0 Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Apr 20 18:10:38 volumio volumio[1202]: info: touch_display: X display number found: 0 Apr 20 18:10:38 volumio startx[2408]: V3D 7.1 not supported by this version of Mesa. Apr 20 18:10:39 volumio kernel: broken atomic modeset userspace detected, disabling atomic Apr 20 18:10:39 volumio startx[2408]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Apr 20 18:10:39 volumio volumio[1202]: info: touch_display: Setting screensaver timeout to 120 seconds. Apr 20 18:10:39 volumio volumio[1202]: info: TidalConnect service started! Apr 20 18:10:39 volumio volumio[1202]: info: TidalConnect service started! Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand status took 38 milliseconds Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:39 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand status took 38 milliseconds Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:39 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:39 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:10:39 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus stop Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 39ms Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces system playlist update Apr 20 18:10:39 volumio volumio[1202]: info: Ignoring MPD Status Update Apr 20 18:10:39 volumio volumio[1202]: info: Apr 20 18:10:39 volumio volumio[1202]: ---------------------------- MPD announces state update: player Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::getState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand status Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 2ms Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 1ms Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand status took 1 milliseconds Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseState Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:39 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:39 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":994,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:10:39 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:10:39 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 54ms Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 20 18:10:39 volumio volumio[1202]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:39 volumio volumio[1202]: verbose: ControllerMpd::parseTrackInfo Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:39 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:39 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:10:39 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:10:39 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: ControllerMpd::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::servicePushState Apr 20 18:10:39 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:39 volumio volumio[1202]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Charlotte Plank - Chemical Fashion","artist":null,"album":null,"uri":"https://listen-msmn.sharp-stream.com/nme2.mp3","trackType":"mp3"} Apr 20 18:10:39 volumio volumio[1202]: verbose: CURRENT POSITION 0 Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState stateService play Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::syncState currentStatus play Apr 20 18:10:39 volumio volumio[1202]: info: Received an update from plugin. extracting info from payload Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: CoreStateMachine::pushState Apr 20 18:10:39 volumio volumio[1202]: info: CoreCommandRouter::volumioPushState Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output update for this device Apr 20 18:10:39 volumio volumio[1202]: info: MRS: Pushing multiroomSync output Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 39ms Apr 20 18:10:39 volumio volumio[1202]: info: ------------------------------ 38ms Apr 20 18:10:39 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: stop Apr 20 18:10:39 volumio volumio[1202]: info: [ASDebug] Togle GPIO: ON Apr 20 18:10:39 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:10:39 volumio volumio[1202]: info: [ASDebug] CurState: play PrevState: play Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 20 18:10:39 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status play Apr 20 18:10:39 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status play Apr 20 18:10:39 volumio sudo[2576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:39 volumio sudo[2576]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:39 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status play Apr 20 18:10:39 volumio sudo[2579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:40 volumio sudo[2579]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:40 volumio volumio[1202]: info: PeppyMeterBasic ---peppymeterbasic status play Apr 20 18:10:40 volumio sudo[2583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:40 volumio systemd[1]: Started peppymeterbasic Daemon. Apr 20 18:10:40 volumio sudo[2583]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:40 volumio sudo[2586]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:40 volumio sudo[2586]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:40 volumio sudo[2591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:40 volumio sudo[2591]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:40 volumio sudo[2576]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio sudo[2594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Apr 20 18:10:40 volumio sudo[2594]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 18:10:40 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:40 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:40 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:40 volumio sudo[2579]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio volumio[1202]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Apr 20 18:10:40 volumio sudo[2586]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio sudo[2583]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio sudo[2594]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio sudo[2591]: pam_unix(sudo:session): session closed for user root Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio volumio[1202]: info: peppymeterbasic Daemon Started Apr 20 18:10:40 volumio volumio[1202]: info: CoreCommandRouter::volumioPlay Apr 20 18:10:40 volumio volumio[1202]: info: CoreStateMachine::play index undefined Apr 20 18:10:40 volumio volumio[1202]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 18:10:40 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:40 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:40 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:40 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:40 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:40 volumio go-librespot[1406]: time="2025-04-20T18:10:40+02:00" level=trace msg="received accesspoint ping" Apr 20 18:10:40 volumio go-librespot[1406]: time="2025-04-20T18:10:40+02:00" level=trace msg="received accesspoint pong ack" Apr 20 18:10:41 volumio volumio[1202]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS aarch64 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Apr 20 18:10:41 volumio go-librespot[1406]: time="2025-04-20T18:10:41+02:00" level=trace msg="sent dealer ping" Apr 20 18:10:41 volumio go-librespot[1406]: time="2025-04-20T18:10:41+02:00" level=trace msg="received dealer pong" Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 20 18:10:41 volumio volumio[1202]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS aarch64 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioGetVisibleSources Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 20 18:10:41 volumio volumio[1202]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 20 18:10:41 volumio volumio[1202]: info: Received Get System Info Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 20 18:10:41 volumio volumio[1202]: info: Discovery: Getting this device information Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:41 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:41 volumio volumio[1202]: info: Listing playlists Apr 20 18:10:41 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 20 18:10:42 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 20 18:10:42 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 20 18:10:42 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:42 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 20 18:10:43 volumio volumio[1202]: info: Received Get System Info Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 20 18:10:43 volumio volumio[1202]: info: Discovery: Getting this device information Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:43 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 20 18:10:43 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 20 18:10:44 volumio volumio[1202]: info: Received Get System Info Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 20 18:10:44 volumio volumio[1202]: info: Discovery: Getting this device information Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:44 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 20 18:10:44 volumio volumio[1202]: info: Executing endpoint metavolumio Apr 20 18:10:44 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 20 18:10:50 volumio volumio[1202]: info: CoreCommandRouter::volumioGetState Apr 20 18:10:50 volumio volumio[1202]: info: CorePlayQueue::getTrack 0 Apr 20 18:10:51 volumio volumio[1202]: info: Starting Uninstall of plugin system_controller - ampswitch Apr 20 18:10:51 volumio volumio[1202]: info: Uninstalling plugin ampswitch Apr 20 18:10:51 volumio volumio[1202]: info: [ASDebug] Port: 5 Apr 20 18:10:51 volumio volumio[1202]: info: [ASDebug] Inverted: false Apr 20 18:10:51 volumio volumio[1202]: info: [ASDebug] Delay: 100 Apr 20 18:10:51 volumio volumio[1202]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 20 18:10:55 volumio volumio[1202]: info: Starting Uninstall of plugin system_controller - ampswitch Apr 20 18:10:55 volumio volumio[1202]: info: Uninstalling plugin ampswitch Apr 20 18:10:55 volumio volumio[1202]: info: [ASDebug] Port: 5 Apr 20 18:10:55 volumio volumio[1202]: info: [ASDebug] Inverted: false Apr 20 18:10:55 volumio volumio[1202]: info: [ASDebug] Delay: 100 Apr 20 18:10:55 volumio volumio[1202]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 18:10:55 volumio volumio[1202]: Error: EBADF: bad file descriptor, close Apr 20 18:10:55 volumio volumio[1202]: at Object.closeSync (fs.js:439:3) Apr 20 18:10:55 volumio volumio[1202]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Apr 20 18:10:55 volumio volumio[1202]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Apr 20 18:10:55 volumio volumio[1202]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Apr 20 18:10:55 volumio volumio[1202]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Apr 20 18:10:55 volumio volumio[1202]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Apr 20 18:10:55 volumio volumio[1202]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Apr 20 18:10:55 volumio volumio[1202]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Apr 20 18:10:55 volumio volumio[1202]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22) Apr 20 18:10:55 volumio volumio[1202]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45) Apr 20 18:10:55 volumio volumio[1202]: at Socket.emit (events.js:315:20) Apr 20 18:10:55 volumio volumio[1202]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 20 18:10:55 volumio volumio[1202]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 20 18:10:55 volumio volumio[1202]: errno: -9, Apr 20 18:10:55 volumio volumio[1202]: syscall: 'close', Apr 20 18:10:55 volumio volumio[1202]: code: 'EBADF' Apr 20 18:10:55 volumio volumio[1202]: } Apr 20 18:10:55 volumio volumio[1202]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 18:10:55 volumio sudo[2920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-20 18:09 Apr 20 18:10:55 volumio sudo[2920]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"