Oct 28 12:35:00 volumio volumio[1161]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 28 12:35:00 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 28 12:35:00 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:00 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:00 volumio volumio[1161]: info: Starting MyVolumio Remote Streaming Endpoints Oct 28 12:35:00 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:00 volumio volumio[1161]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 28 12:35:00 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 28 12:35:01 volumio upmpdcli[1605]: writing RSA key Oct 28 12:35:04 volumio volumio[1161]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 28 12:35:04 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 28 12:35:04 volumio volumio[1161]: info: Streaming services startup Oct 28 12:35:04 volumio volumio[1161]: info: Starting Streaming Daemon Oct 28 12:35:04 volumio sudo[1617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 28 12:35:04 volumio sudo[1617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:04 volumio volumio[1161]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 28 12:35:04 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 28 12:35:04 volumio sudo[1617]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:04 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:04 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::volumioPlay Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::play index undefined Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 28 12:35:04 volumio volumio[1161]: info: CoreCommandRouter::volumioNext Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::next Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::stop Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:04 volumio volumio[1161]: info: CorePlayQueue::getTrack 0 Oct 28 12:35:04 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Oct 28 12:35:04 volumio volumio[1161]: info: CorePlayQueue::getTrack 0 Oct 28 12:35:04 volumio volumio[1161]: verbose: ControllerMpd::clearAddPlayTracks USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac Oct 28 12:35:05 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 12:35:05 volumio volumio[1161]: info: CoreStateMachine::play index undefined Oct 28 12:35:05 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:05 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:05 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Oct 28 12:35:05 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:05 volumio volumio[1161]: verbose: ControllerMpd::clearAddPlayTracks USB/2TB_SSD_T7/Hans Theessink - 75 Birthday Bash 2025/03 - Hans Theessink - Seven Spanish Angels.flac Oct 28 12:35:05 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 12:35:05 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Oct 28 12:35:05 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Oct 28 12:35:05 volumio volumio[1161]: error: Cannot start Volumio Streaming Daemon Oct 28 12:35:05 volumio volumio[1161]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 28 12:35:05 volumio volumio[1161]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 28 12:35:05 volumio volumio[1161]: info: CoreCommandRouter::volumioGetQueue Oct 28 12:35:05 volumio volumio[1161]: info: CoreStateMachine::getQueue Oct 28 12:35:05 volumio volumio[1161]: info: CorePlayQueue::getQueue Oct 28 12:35:05 volumio volumio[1161]: info: sendMpdCommand stop took 867 milliseconds Oct 28 12:35:05 volumio volumio[1161]: info: sendMpdCommand stop took 746 milliseconds Oct 28 12:35:05 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 12:35:05 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clear took 365 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clear took 365 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac" Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "USB/2TB_SSD_T7/Hans Theessink - 75 Birthday Bash 2025/03 - Hans Theessink - Seven Spanish Angels.flac" Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 28 12:35:06 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:06 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 167ms Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 165ms Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand add "USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac" took 164 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand add "USB/2TB_SSD_T7/Hans Theessink - 75 Birthday Bash 2025/03 - Hans Theessink - Seven Spanish Angels.flac" took 163 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 164ms Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 163ms Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:06 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 61ms Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 60ms Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand play took 47 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand play took 46 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 97ms Oct 28 12:35:06 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:06 volumio volumio[1161]: info: ------------------------------ 59ms Oct 28 12:35:06 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:06 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:06 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand status took 123 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand status took 124 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand status took 140 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand status took 139 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:06 volumio volumio[1161]: info: Oct 28 12:35:06 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:06 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:06 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clearerror took 327 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clearerror took 327 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clearerror took 310 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand clearerror took 309 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 238 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 257 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 242 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 242 milliseconds Oct 28 12:35:06 volumio volumio[1161]: info: sendMpdCommand status took 240 milliseconds Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:06 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:07 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:07 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:07 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":94,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sunshine Of Your Wub","artist":"Yookie","album":null,"uri":"USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac","trackType":"flac"} Oct 28 12:35:07 volumio volumio[1161]: verbose: CURRENT POSITION 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:07 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":94,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sunshine Of Your Wub","artist":"Yookie","album":null,"uri":"USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac","trackType":"flac"} Oct 28 12:35:07 volumio volumio[1161]: verbose: CURRENT POSITION 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:07 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":94,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sunshine Of Your Wub","artist":"Yookie","album":null,"uri":"USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac","trackType":"flac"} Oct 28 12:35:07 volumio volumio[1161]: verbose: CURRENT POSITION 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:07 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":94,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sunshine Of Your Wub","artist":"Yookie","album":null,"uri":"USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac","trackType":"flac"} Oct 28 12:35:07 volumio volumio[1161]: verbose: CURRENT POSITION 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:07 volumio volumio[1161]: info: ------------------------------ 670ms Oct 28 12:35:07 volumio volumio[1161]: info: ------------------------------ 670ms Oct 28 12:35:07 volumio volumio[1161]: info: ------------------------------ 617ms Oct 28 12:35:07 volumio volumio[1161]: info: ------------------------------ 616ms Oct 28 12:35:07 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 317 milliseconds Oct 28 12:35:07 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:07 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":94,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Sunshine Of Your Wub","artist":"Yookie","album":null,"uri":"USB/2TB_SSD_T7/Yookie - Sunshine Of Your Wub (2024).flac","trackType":"flac"} Oct 28 12:35:07 volumio volumio[1161]: verbose: CURRENT POSITION 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:07 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:07 volumio volumio[1161]: info: ------------------------------ 608ms Oct 28 12:35:07 volumio volumio[1161]: error: MyVolumio Custom Token format not valid, refreshing it Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:07 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:07 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:07 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:07 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:07 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:07 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:07 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:07 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:07 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:07 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:07 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:07 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:08 volumio volumio[1161]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 28 12:35:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:08 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:08 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:08 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 28 12:35:09 volumio volumio[1161]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 28 12:35:09 volumio volumio[1161]: info: Received Get System Version Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 28 12:35:09 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:09 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:09 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:09 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:09 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:09 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Oct 28 12:35:09 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:10 volumio volumio[1161]: info: MyVolumio token set successfully Oct 28 12:35:10 volumio volumio[1161]: info: MYVOLUMIO: Adding device Oct 28 12:35:10 volumio volumio[1161]: info: MYVOLUMIO: Evaluating Server Oct 28 12:35:10 volumio volumio[1161]: info: MyVolumio login type: Token Oct 28 12:35:11 volumio volumio[1161]: info: MyVolumio Plan changed: premium Oct 28 12:35:11 volumio volumio[1161]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Oct 28 12:35:11 volumio volumio[1161]: info: Removing browser output: myVolumio user plan is not superstar Oct 28 12:35:11 volumio volumio[1161]: info: Removing audio output: Oct 28 12:35:11 volumio volumio[1161]: info: MYVOLUMIO: Adding device Oct 28 12:35:11 volumio volumio[1161]: info: MYVOLUMIO: Evaluating Server Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:11 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:11 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:11 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:11 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:11 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:11 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:11 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:11 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:11 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:11 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:11 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:11 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:11 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:12 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:12 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:12 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:12 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:12 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:12 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:12 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:12 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:12 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:12 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:12 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:12 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 28 12:35:12 volumio volumio[1161]: info: Received Get System Info Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:35:12 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:12 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:35:12 volumio volumio[1161]: info: Setting Geolocation for MyVolumio to eu7 Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:12 volumio volumio-remote-updater[733]: Test mode enabled Oct 28 12:35:12 volumio volumio-remote-updater[733]: Alpha mode disabled Oct 28 12:35:12 volumio volumio-remote-updater[733]: Alpha legacy test mode disabled Oct 28 12:35:12 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 28 12:35:13 volumio volumio[1161]: info: Setting Geolocation for MyVolumio to eu7 Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:13 volumio volumio[1161]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 28 12:35:13 volumio volumio[1161]: info: Remote config written successfully Oct 28 12:35:13 volumio volumio[1161]: info: Starting Tunnel 1 Oct 28 12:35:13 volumio volumio[1161]: info: Starting Tunnel Connection Checker Oct 28 12:35:13 volumio volumio[1161]: info: Completed starting MyVolumio Plugin Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:13 volumio volumio[1161]: info: CorePlayQueue::getTrack 1642 Oct 28 12:35:13 volumio volumio[1161]: info: Updating MyVolumio device info Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:13 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:14 volumio volumio[1161]: info: Updating MyVolumio device info Oct 28 12:35:14 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:14 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:14 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:14 volumio volumio[1161]: info: MYVolumio Device enabled Oct 28 12:35:14 volumio volumio[1161]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Oct 28 12:35:14 volumio volumio[1161]: info: MyVolumio status changed Oct 28 12:35:14 volumio volumio[1161]: info: Streaming services startup Oct 28 12:35:14 volumio volumio[1161]: info: Starting Streaming Daemon Oct 28 12:35:14 volumio volumio[1161]: info: Successfully Added MyVolumio device Oct 28 12:35:14 volumio volumio[1161]: info: Successfully Added MyVolumio device Oct 28 12:35:14 volumio sudo[1728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 28 12:35:14 volumio sudo[1728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:14 volumio sudo[1728]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:14 volumio volumio[1161]: error: Cannot start Volumio Streaming Daemon Oct 28 12:35:14 volumio volumio[1161]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 28 12:35:14 volumio volumio[1161]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 28 12:35:14 volumio volumio[1161]: info: Successfully Updated MyVolumio device Oct 28 12:35:15 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 28 12:35:15 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Oct 28 12:35:15 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Oct 28 12:35:16 volumio volumio[1161]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Oct 28 12:35:16 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Oct 28 12:35:17 volumio volumio[1161]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Oct 28 12:35:17 volumio sudo[1739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 28 12:35:17 volumio sudo[1739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:17 volumio sudo[1739]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:18 volumio volumio[1161]: info: MRS: MultiRoom plugin initialized Oct 28 12:35:18 volumio volumio[1161]: info: MRS: STOPPING SNAPCLIENT Oct 28 12:35:18 volumio volumio[1161]: info: MRS: Snap server stop Oct 28 12:35:18 volumio volumio[1161]: info: MRS: STOPPING volumioStreaming Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Oct 28 12:35:18 volumio sudo[1756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 28 12:35:18 volumio sudo[1756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:18 volumio sudo[1758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 28 12:35:18 volumio sudo[1758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:18 volumio sudo[1763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 28 12:35:18 volumio sudo[1763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:18 volumio sudo[1763]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:18 volumio sudo[1760]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 28 12:35:18 volumio sudo[1760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:18 volumio sudo[1758]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Oct 28 12:35:18 volumio sudo[1756]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:18 volumio sudo[1760]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Oct 28 12:35:18 volumio volumio[1161]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Oct 28 12:35:18 volumio volumio[1161]: info: Preparing to generate the ALSA configuration file Oct 28 12:35:18 volumio volumio[1161]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 28 12:35:18 volumio volumio[1161]: info: Reading ALSA contributions from plugins. Oct 28 12:35:19 volumio volumio[1161]: info: Successfully Updated MyVolumio device Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioNext Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::next Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::play index undefined Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::startPlaybackTimer Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::clearAddPlayTracks USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::updateTrackBlock Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrackBlock Oct 28 12:35:19 volumio volumio[1161]: info: MRS: Removed streaming files Oct 28 12:35:19 volumio volumio[1161]: info: MRS: volumioStreaming STOPPED Oct 28 12:35:19 volumio volumio[1161]: info: MRS: SNAPSERVER STOPPED Oct 28 12:35:19 volumio volumio[1161]: info: MRS: SNAPCLIENT STOPPED Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:19 volumio volumio[1161]: info: sendMpdCommand stop took 318 milliseconds Oct 28 12:35:19 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clear Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:19 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:19 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:19 volumio volumio[1161]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:19 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:19 volumio volumio[1161]: info: sendMpdCommand status took 81 milliseconds Oct 28 12:35:19 volumio volumio[1161]: info: sendMpdCommand clear took 81 milliseconds Oct 28 12:35:19 volumio volumio[1161]: info: sendMpdCommand status took 80 milliseconds Oct 28 12:35:19 volumio volumio[1161]: info: sendMpdCommand status took 79 milliseconds Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand add "USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac" Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:19 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:19 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 28 12:35:19 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::syncState stateService stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: No code Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 28 12:35:19 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::syncState stateService stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: No code Oct 28 12:35:19 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:19 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:19 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:19 volumio volumio[1161]: info: ------------------------------ 320ms Oct 28 12:35:19 volumio volumio[1161]: info: ------------------------------ 320ms Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:19 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:19 volumio volumio[1161]: info: Oct 28 12:35:19 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:19 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::volumioGetBrowseSources Oct 28 12:35:20 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 28 12:35:20 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:20 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 685ms Oct 28 12:35:20 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 683 milliseconds Oct 28 12:35:20 volumio volumio[1161]: info: sendMpdCommand add "USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac" took 684 milliseconds Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 444ms Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 418ms Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand play Oct 28 12:35:20 volumio volumio[1161]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 768ms Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:20 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces system playlist update Oct 28 12:35:20 volumio volumio[1161]: info: Ignoring MPD Status Update Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 501ms Oct 28 12:35:20 volumio volumio[1161]: info: sendMpdCommand play took 500 milliseconds Oct 28 12:35:20 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 435ms Oct 28 12:35:20 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:20 volumio volumio[1161]: info: ------------------------------ 435ms Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:20 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:20 volumio volumio[1161]: info: Oct 28 12:35:20 volumio volumio[1161]: ---------------------------- MPD announces state update: player Oct 28 12:35:20 volumio volumio[1161]: info: ControllerMpd::getState Oct 28 12:35:20 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand status Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand status took 120 milliseconds Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand status took 120 milliseconds Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand status took 119 milliseconds Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand status took 119 milliseconds Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseState Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand clearerror took 114 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand clearerror took 114 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand clearerror took 114 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand clearerror took 113 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 68 milliseconds Oct 28 12:35:21 volumio volumio[1161]: info: sendMpdCommand playlistinfo took 67 milliseconds Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:21 volumio volumio[1161]: verbose: ControllerMpd::parseTrackInfo Oct 28 12:35:21 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Beat Crazy","artist":"Joe Jackson Band","album":"Afterlife","uri":"USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac","trackType":"flac"} Oct 28 12:35:21 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:21 volumio sudo[1791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Oct 28 12:35:21 volumio sudo[1791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:21 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Beat Crazy","artist":"Joe Jackson Band","album":"Afterlife","uri":"USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac","trackType":"flac"} Oct 28 12:35:21 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:21 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Beat Crazy","artist":"Joe Jackson Band","album":"Afterlife","uri":"USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac","trackType":"flac"} Oct 28 12:35:21 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:21 volumio volumio[1161]: info: ControllerMpd::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":261,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Beat Crazy","artist":"Joe Jackson Band","album":"Afterlife","uri":"USB/2TB_SSD_T7/2004 - Afterlife/07 - Beat Crazy.flac","trackType":"flac"} Oct 28 12:35:21 volumio volumio[1161]: verbose: CURRENT POSITION 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState stateService pause Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::syncState currentStatus stop Oct 28 12:35:21 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:21 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:21 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 28 12:35:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 28 12:35:21 volumio volumio[1161]: info: ------------------------------ 398ms Oct 28 12:35:21 volumio volumio[1161]: info: ------------------------------ 397ms Oct 28 12:35:21 volumio volumio[1161]: info: ------------------------------ 397ms Oct 28 12:35:21 volumio volumio[1161]: info: ------------------------------ 396ms Oct 28 12:35:21 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Oct 28 12:35:21 volumio sudo[1791]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:21 volumio autossh[1795]: port set to 0, monitoring disabled Oct 28 12:35:21 volumio autossh[1795]: starting ssh (count 1) Oct 28 12:35:21 volumio autossh[1795]: ssh child pid is 1798 Oct 28 12:35:21 volumio volumiossh-tunnel[1798]: Warning: Permanently added '[eu7.myvolumio.org]:2222' (RSA) to the list of known hosts. Oct 28 12:35:21 volumio volumio[1161]: info: Remote SSH Started Oct 28 12:35:22 volumio volumio[1161]: info: Asound.conf file written Oct 28 12:35:22 volumio sudo[1802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 28 12:35:22 volumio sudo[1802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:22 volumio sudo[1802]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:22 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 28 12:35:22 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 28 12:35:22 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 28 12:35:22 volumio volumio[1161]: info: Output device has changed, restarting MPD Oct 28 12:35:22 volumio volumio[1161]: info: Output device has changed, restarting Shairport Sync Oct 28 12:35:22 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:22 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:22 volumio sudo[1808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 12:35:22 volumio sudo[1808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:23 volumio sudo[1810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 12:35:23 volumio sudo[1810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:23 volumio sudo[1808]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:23 volumio volumio[1161]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 12:35:23 volumio volumio[1161]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 28 12:35:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 28 12:35:23 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Oct 28 12:35:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: [FUNC] onStart Oct 28 12:35:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Oct 28 12:35:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Oct 28 12:35:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Oct 28 12:35:23 volumio volumio[1161]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Oct 28 12:35:23 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Oct 28 12:35:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 28 12:35:23 volumio volumio[1161]: info: MRS: Pushing multiroomSync output for this device Oct 28 12:35:23 volumio volumio[1161]: info: MRS: Pushing multiroomSync output Oct 28 12:35:23 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 28 12:35:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 28 12:35:23 volumio systemd[1]: mpd.service: Consumed 3.392s CPU time. Oct 28 12:35:23 volumio volumio[1161]: info: Adding audio output: Oct 28 12:35:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 28 12:35:23 volumio volumio[1161]: info: Adding audio output: Oct 28 12:35:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 28 12:35:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 28 12:35:23 volumio bluetoothd[722]: Path / reserved for Adv Monitor app :1.17 Oct 28 12:35:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 28 12:35:23 volumio bluetoothd[722]: Adv Monitor app :1.17 disconnected from D-Bus Oct 28 12:35:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 28 12:35:23 volumio volumio[1161]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 28 12:35:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:23 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Oct 28 12:35:23 volumio volumio[1161]: info: Adding METAVOLUMIO REST API Endpoints Oct 28 12:35:23 volumio volumio[1161]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 28 12:35:23 volumio volumio[1161]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 28 12:35:23 volumio volumio[1161]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 28 12:35:23 volumio volumio[1161]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 28 12:35:23 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Oct 28 12:35:23 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Oct 28 12:35:23 volumio volumio[1161]: info: Preparing CD Folders Oct 28 12:35:23 volumio volumio[1161]: info: Adding CD REST API Endpoints Oct 28 12:35:23 volumio volumio[1161]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 28 12:35:23 volumio volumio[1161]: info: Starting UDEV Watcher for CD Oct 28 12:35:23 volumio volumio[1161]: info: Detecting CD presence with UDEV Oct 28 12:35:23 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 28 12:35:23 volumio sudo[1823]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 12:35:23 volumio sudo[1823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 28 12:35:23 volumio sudo[1823]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:24 volumio mpd[1827]: 2025-10-28T12:35:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 28 12:35:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 28 12:35:24 volumio sudo[1810]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:28 volumio volumio[1161]: warn: [cd-plugin] cdspeedctl: device or media not ready Oct 28 12:35:28 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Oct 28 12:35:28 volumio volumio[1161]: info: Adding inputs REST Endpoints Oct 28 12:35:28 volumio volumio[1161]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 28 12:35:28 volumio volumio[1161]: info: Scanning Audio Inputs Oct 28 12:35:28 volumio volumio[1161]: info: Checking against Known Cards name Oct 28 12:35:28 volumio volumio[1161]: info: Checking against Known Cards name Oct 28 12:35:28 volumio volumio[1161]: info: Adding Server instance for streaming Oct 28 12:35:28 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Oct 28 12:35:29 volumio volumio[1161]: error: Hi Res Audio Failed Login: Missing Login Data Oct 28 12:35:29 volumio volumio[1161]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 28 12:35:29 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Oct 28 12:35:29 volumio volumio[1161]: info: Refreshing TIDAL token Oct 28 12:35:29 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Oct 28 12:35:29 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Oct 28 12:35:29 volumio volumio[1161]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Oct 28 12:35:29 volumio volumio[1161]: info: [MyVolumio PluginManager] Plugin qobuzconnect disabled by user. Not starting Oct 28 12:35:29 volumio sudo[1840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 28 12:35:29 volumio sudo[1840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:29 volumio volumio[1161]: info: Stopping AccessToken refresher cron for QOBUZ Oct 28 12:35:29 volumio sudo[1840]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:29 volumio volumio[1161]: info: AccessToken refresher cron started for QOBUZ Oct 28 12:35:29 volumio volumio[1161]: info: Adding QOBUZ REST API Endpoints Oct 28 12:35:29 volumio volumio[1161]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 28 12:35:29 volumio volumio[1161]: info: MRS: Getting audio outputs on start Oct 28 12:35:29 volumio volumio[1161]: info: MRS: Requesting all other devices output Oct 28 12:35:29 volumio volumio[1161]: error: Upnp client error: Error: This socket has been ended by the other party Oct 28 12:35:29 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:29 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:29 volumio volumio[1161]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 28 12:35:29 volumio volumio[1161]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Oct 28 12:35:29 volumio volumio[1161]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 28 12:35:29 volumio volumio[1161]: info: MPD Permissions set Oct 28 12:35:30 volumio sudo[1845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 28 12:35:30 volumio sudo[1845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:30 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Oct 28 12:35:30 volumio sudo[1845]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:30 volumio volumiobt[1849]: INFO [BTSTART] Ensuring Bluetooth directory exists... Oct 28 12:35:30 volumio sudo[1850]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Oct 28 12:35:30 volumio sudo[1850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:30 volumio sudo[1850]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:30 volumio sudo[1852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Oct 28 12:35:30 volumio sudo[1852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:30 volumio sudo[1852]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:30 volumio volumiobt[1854]: INFO [BTSTART] Powering on Bluetooth if needed... Oct 28 12:35:30 volumio bluetoothd[722]: Adv Monitor app :1.19 disconnected from D-Bus Oct 28 12:35:30 volumio volumiobt[1857]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Oct 28 12:35:30 volumio volumiobt[1858]: [176B blob data] Oct 28 12:35:30 volumio volumiobt[1858]: [157B blob data] Oct 28 12:35:30 volumio volumiobt[1858]: [157B blob data] Oct 28 12:35:30 volumio volumiobt[1858]: [157B blob data] Oct 28 12:35:30 volumio volumiobt[1858]: [113B blob data] Oct 28 12:35:30 volumio volumiobt[1858]: [bluetoothctl]> discoverable on Oct 28 12:35:30 volumio volumiobt[1858]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Oct 28 12:35:30 volumio volumiobt[1858]: [bluetoothctl]> pairable on Oct 28 12:35:30 volumio bluetoothd[722]: Path / reserved for Adv Monitor app :1.20 Oct 28 12:35:30 volumio bluetoothd[722]: Adv Monitor app :1.20 disconnected from D-Bus Oct 28 12:35:30 volumio volumiobt[1858]: [bluetoothctl]> Oct 28 12:35:30 volumio volumiobt[1859]: INFO [BTSTART] Registering Bluetooth agent... Oct 28 12:35:30 volumio volumiobt[1860]: [NEW] Media /org/bluez/hci0 Oct 28 12:35:30 volumio volumiobt[1860]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio volumiobt[1860]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio volumiobt[1860]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio bluetoothd[722]: Adv Monitor app :1.21 disconnected from D-Bus Oct 28 12:35:30 volumio volumiobt[1861]: No agent is registered Oct 28 12:35:30 volumio volumiobt[1861]: [NEW] Media /org/bluez/hci0 Oct 28 12:35:30 volumio volumiobt[1861]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio volumiobt[1861]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio volumiobt[1861]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Oct 28 12:35:30 volumio bluetoothd[722]: Adv Monitor app :1.22 disconnected from D-Bus Oct 28 12:35:30 volumio volumiobt[1862]: INFO [BTSTART] Agent registered successfully. Oct 28 12:35:30 volumio volumiobt[1866]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Oct 28 12:35:31 volumio volumiobt[1867]: INFO:a2dp-agent:Connecting to system bus. Oct 28 12:35:31 volumio volumiobt[1867]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Oct 28 12:35:31 volumio volumiobt[1867]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Oct 28 12:35:31 volumio volumiobt[1867]: INFO:a2dp-agent:Registering agent. Oct 28 12:35:31 volumio volumiobt[1867]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Oct 28 12:35:31 volumio volumiobt[1867]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Oct 28 12:35:32 volumio volumio[1161]: info: TidalConnect service stoped! Oct 28 12:35:32 volumio volumio[1161]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::volumioStop Oct 28 12:35:32 volumio volumio[1161]: info: CoreStateMachine::stop Oct 28 12:35:32 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:32 volumio volumio[1161]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Oct 28 12:35:32 volumio volumio[1161]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:32 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:33 volumio sudo[1892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 28 12:35:33 volumio sudo[1892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:33 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 28 12:35:33 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 28 12:35:33 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:33 volumio volumio[1161]: info: Starting Shairport Sync Oct 28 12:35:33 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:33 volumio volumio[1161]: info: Access Token successfully retrieved Oct 28 12:35:33 volumio sudo[1892]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:33 volumio mpd_monitor.sh[1898]: MPD Monitor Service: Starting MPD Monitor Service Oct 28 12:35:33 volumio volumio[1161]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:33 volumio volumio[1161]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:33 volumio sudo[1900]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 12:35:33 volumio sudo[1900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:33 volumio volumio[1161]: info: Preparing to generate the ALSA configuration file Oct 28 12:35:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 28 12:35:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 28 12:35:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:33 volumio systemd[1]: shairport-sync.service: Consumed 1.408s CPU time. Oct 28 12:35:33 volumio volumio[1161]: info: Successfully started MPD Monitor Oct 28 12:35:33 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:33 volumio sudo[1900]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:33 volumio volumio[1161]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.sTaNHCLHK1Xljb8UrMAWnbmWjlr1.25731239afaa58397ef87b396a025d24.state.status' Oct 28 12:35:33 volumio volumio[1161]: info: Shairport-Sync Started Oct 28 12:35:33 volumio sudo[1923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 28 12:35:33 volumio sudo[1923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:34 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 28 12:35:34 volumio sudo[1923]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:34 volumio volumio[1161]: info: Successfully retrieved User Session From TIDAL Oct 28 12:35:34 volumio volumio[1161]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 28 12:35:34 volumio volumio[1161]: info: Asound.conf file written Oct 28 12:35:34 volumio sudo[1933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 28 12:35:34 volumio sudo[1933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:34 volumio sudo[1933]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:34 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 28 12:35:34 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 28 12:35:34 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 28 12:35:34 volumio volumio[1161]: info: Output device has changed, restarting MPD Oct 28 12:35:34 volumio volumio[1161]: info: Output device has changed, restarting Shairport Sync Oct 28 12:35:34 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:34 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:34 volumio sudo[1939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 12:35:34 volumio sudo[1939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:34 volumio sudo[1941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 12:35:34 volumio sudo[1941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:34 volumio sudo[1939]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 28 12:35:34 volumio volumio[1161]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 12:35:34 volumio volumio[1161]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 28 12:35:34 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:35 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 28 12:35:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 28 12:35:35 volumio systemd[1]: mpd.service: Consumed 1.482s CPU time. Oct 28 12:35:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 28 12:35:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 28 12:35:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 28 12:35:35 volumio volumio[1161]: error: Error starting TidalConnect Cannot read properties of undefined (reading 'sendRevoke') {"stack":"TypeError: Cannot read properties of undefined (reading 'sendRevoke')\n at ControllerTidalconnect.stopTidalConnect (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:8524)\n at ControllerTidalconnect.restartService (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:8816)\n at /volumio/node_modules/v-conf/index.js:166:13\n at /volumio/node_modules/multimap/index.js:140:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:139:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:133:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:138:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:163:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at process.processTicksAndRejections (node:internal/process/task_queues:77:11)"} Oct 28 12:35:35 volumio volumio[1161]: info: Preparing to generate the ALSA configuration file Oct 28 12:35:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 28 12:35:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 28 12:35:35 volumio sudo[1951]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 12:35:35 volumio sudo[1951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 28 12:35:35 volumio sudo[1951]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:35 volumio sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 28 12:35:35 volumio sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:35 volumio volumio[1161]: info: Successfully retrieved User Subscription From TIDAL Oct 28 12:35:35 volumio volumio[1161]: info: Adding TIDAL to Browse Sources Oct 28 12:35:35 volumio volumio[1161]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 28 12:35:35 volumio volumio[1161]: info: [1761651335354] CoreMusicLibrary::Adding element TIDAL Oct 28 12:35:35 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 12:35:35 volumio volumio[1161]: Cannot find translation for source Radio Paradise Oct 28 12:35:35 volumio volumio[1161]: Cannot find translation for source TIDAL Oct 28 12:35:35 volumio volumio[1161]: info: Stopping AccessToken refresher cron Oct 28 12:35:35 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Oct 28 12:35:35 volumio systemd[1]: vtcs.service: Deactivated successfully. Oct 28 12:35:35 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Oct 28 12:35:35 volumio sudo[1955]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:35 volumio volumio[1161]: info: AccessToken refresher cron started Oct 28 12:35:35 volumio volumio[1161]: info: Adding TIDAL REST API Endpoints Oct 28 12:35:35 volumio volumio[1161]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 28 12:35:35 volumio volumio[1161]: info: Reading ALSA contributions from plugins. Oct 28 12:35:35 volumio volumio[1161]: info: Executing endpoint tc_getconfig Oct 28 12:35:35 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 28 12:35:35 volumio volumio[1161]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 28 12:35:35 volumio volumio[1161]: info: MPD Permissions set Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:36 volumio mpd[1953]: 2025-10-28T12:35:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 28 12:35:36 volumio volumio[1161]: info: Starting Shairport Sync Oct 28 12:35:36 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 28 12:35:36 volumio sudo[1967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 12:35:36 volumio sudo[1967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:36 volumio sudo[1941]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 28 12:35:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 28 12:35:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:36 volumio systemd[1]: shairport-sync.service: Consumed 1.250s CPU time. Oct 28 12:35:36 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:35:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:36 volumio sudo[1967]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:37 volumio volumio[1161]: info: Shairport-Sync Started Oct 28 12:35:37 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:37 volumio volumio[1161]: info: Asound.conf file written Oct 28 12:35:37 volumio sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 28 12:35:37 volumio sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:37 volumio sudo[1994]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:37 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Oct 28 12:35:37 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Oct 28 12:35:37 volumio volumio[1161]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Oct 28 12:35:37 volumio volumio[1161]: info: Output device has changed, restarting MPD Oct 28 12:35:37 volumio volumio[1161]: info: Output device has changed, restarting Shairport Sync Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:37 volumio sudo[2000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 28 12:35:37 volumio sudo[2000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:37 volumio sudo[2000]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:37 volumio sudo[2002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 28 12:35:37 volumio sudo[2002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 28 12:35:37 volumio volumio[1161]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 28 12:35:37 volumio volumio[1161]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:37 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 28 12:35:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 28 12:35:37 volumio systemd[1]: mpd.service: Consumed 1.521s CPU time. Oct 28 12:35:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 28 12:35:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 28 12:35:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 28 12:35:37 volumio volumio[1161]: error: Error starting TidalConnect Cannot read properties of undefined (reading 'sendRevoke') {"stack":"TypeError: Cannot read properties of undefined (reading 'sendRevoke')\n at ControllerTidalconnect.stopTidalConnect (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:8524)\n at ControllerTidalconnect.restartService (/myvolumio/plugins/music_service/tidalconnect/tidalconnect_real:1:8816)\n at /volumio/node_modules/v-conf/index.js:166:13\n at /volumio/node_modules/multimap/index.js:140:9\n at Array.forEach ()\n at /volumio/node_modules/multimap/index.js:139:13\n at mapEach (/volumio/node_modules/multimap/index.js:9:5)\n at Multimap.forEachEntry (/volumio/node_modules/multimap/index.js:133:5)\n at Multimap.forEach (/volumio/node_modules/multimap/index.js:138:10)\n at Config.set (/volumio/node_modules/v-conf/index.js:163:20)\n at Promise._successFn (/volumio/app/plugins/audio_interface/alsa_controller/index.js:2112:39)\n at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)\n at process.processTicksAndRejections (node:internal/process/task_queues:77:11)"} Oct 28 12:35:37 volumio sudo[2013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 28 12:35:37 volumio sudo[2013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 28 12:35:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 28 12:35:37 volumio volumio[1161]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Oct 28 12:35:37 volumio volumio[1161]: info: MPD Permissions set Oct 28 12:35:37 volumio volumio[1161]: info: TidalConnect service started! Oct 28 12:35:37 volumio volumio[1161]: [Metrics] CommandRouter: 70s 866.36ms Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::volumiosetStartupVolume Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:37 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:38 volumio sudo[2015]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 28 12:35:38 volumio sudo[2015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 28 12:35:38 volumio sudo[2013]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:38 volumio sudo[2015]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::Close All Modals sent Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::Close All Modals sent Oct 28 12:35:38 volumio volumio[1161]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Oct 28 12:35:38 volumio volumio[1161]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 28 12:35:38 volumio volumio[1161]: aplay: main:831: audio open error: Invalid argument Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 28 12:35:38 volumio volumio[1161]: info: TidalConnect service stoped! Oct 28 12:35:38 volumio volumio[1161]: info: Starting Shairport Sync Oct 28 12:35:39 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 28 12:35:39 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 28 12:35:39 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 28 12:35:39 volumio volumio[1161]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:39 volumio volumio[1161]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:39 volumio sudo[2038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 28 12:35:39 volumio sudo[2038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 28 12:35:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 28 12:35:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:39 volumio systemd[1]: shairport-sync.service: Consumed 1.302s CPU time. Oct 28 12:35:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 28 12:35:39 volumio sudo[2038]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:39 volumio mpd[2018]: 2025-10-28T12:35:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 28 12:35:39 volumio sudo[2043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 28 12:35:39 volumio sudo[2043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:39 volumio volumio[1161]: info: Shairport-Sync Started Oct 28 12:35:39 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Oct 28 12:35:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 28 12:35:39 volumio sudo[2043]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:39 volumio sudo[2002]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:39 volumio sudo[2066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 28 12:35:39 volumio sudo[2066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:40 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 28 12:35:40 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 28 12:35:40 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:40 volumio volumio[1161]: info: Executing endpoint tc_getconfig Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 28 12:35:40 volumio vtcs[2063]: STARTING TidalConnect services, version: 1.5.1-beta1 Oct 28 12:35:40 volumio vtcs[2063]: STARTED TidalConnect services. Oct 28 12:35:40 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:40 volumio mpd_monitor.sh[2070]: MPD Monitor Service: Starting MPD Monitor Service Oct 28 12:35:40 volumio sudo[2066]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:40 volumio volumio[1161]: error: updateQueue error: null Oct 28 12:35:40 volumio volumio[1161]: info: Successfully started MPD Monitor Oct 28 12:35:40 volumio volumio[1161]: info: Executing endpoint tc_connect Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 28 12:35:40 volumio volumio[1161]: info: Connecting to TidalConnect Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:40 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:40 volumio volumio[1161]: info: MRS: Pushing multiroomSync output update for this device Oct 28 12:35:40 volumio volumio[1161]: info: MRS: Pushing multiroomSync output Oct 28 12:35:40 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:40 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::servicePushState Oct 28 12:35:40 volumio volumio[1161]: info: CoreStateMachine::pushState Oct 28 12:35:40 volumio volumio[1161]: info: CoreCommandRouter::volumioPushState Oct 28 12:35:40 volumio volumio[1161]: info: MRS: Pushing multiroomSync output update for this device Oct 28 12:35:40 volumio volumio[1161]: info: MRS: Pushing multiroomSync output Oct 28 12:35:40 volumio volumio[1161]: info: CorePlayQueue::getTrack 516 Oct 28 12:35:40 volumio volumio[1161]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Oct 28 12:35:40 volumio volumio[1161]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.sTaNHCLHK1Xljb8UrMAWnbmWjlr1.25731239afaa58397ef87b396a025d24.state.status' Oct 28 12:35:41 volumio volumio[1161]: info: TidalConnect service stoped! Oct 28 12:35:41 volumio volumio[1161]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:41 volumio volumio[1161]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 28 12:35:41 volumio sudo[2114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 28 12:35:41 volumio sudo[2114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:41 volumio sudo[2114]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:42 volumio volumio[1161]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 28 12:35:42 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 28 12:35:42 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 28 12:35:42 volumio sudo[2128]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 28 12:35:42 volumio sudo[2128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:42 volumio sudo[2130]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 28 12:35:42 volumio sudo[2130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:42 volumio sudo[2139]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 28 12:35:42 volumio sudo[2139]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:42 volumio sudo[2130]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:42 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Oct 28 12:35:42 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Oct 28 12:35:42 volumio sudo[2141]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 28 12:35:42 volumio sudo[2141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:42 volumio sudo[2139]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:42 volumio sudo[2128]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:42 volumio sudo[2149]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 28 12:35:43 volumio sudo[2141]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:43 volumio sudo[2156]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 28 12:35:43 volumio sudo[2153]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:35:43 volumio sudo[2153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:43 volumio sudo[2153]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:43 volumio sudo[2149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:43 volumio sudo[2156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:43 volumio sudo[2149]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:43 volumio volumio[1161]: info: Executing endpoint metavolumio Oct 28 12:35:43 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 28 12:35:43 volumio sudo[2160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 28 12:35:43 volumio sudo[2160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:35:43 volumio volumio[1161]: info: TidalConnect service started! Oct 28 12:35:43 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 28 12:35:43 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 28 12:35:43 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:43 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 28 12:35:43 volumio mpd_monitor.sh[2165]: MPD Monitor Service: Starting MPD Monitor Service Oct 28 12:35:43 volumio sudo[2160]: pam_unix(sudo:session): session closed for user root Oct 28 12:35:43 volumio volumio[1161]: info: Successfully started MPD Monitor Oct 28 12:35:44 volumio volumio[1161]: info: TidalConnect service started! Oct 28 12:35:45 volumio volumio[1161]: info: BOOT COMPLETED Oct 28 12:35:45 volumio sudo[2156]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:03 volumio volumio[1161]: verbose: New Socket.io Connection to 192.168.178.100 from 192.168.178.48 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:144.0) Gecko/20100101 Firefox/144.0 Engine version: 3 Transport: polling Total Clients: 9 Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetVisibleSources Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 28 12:36:03 volumio volumio[1161]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 28 12:36:03 volumio volumio[1161]: info: Received Get System Info Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 28 12:36:03 volumio volumio[1161]: info: Discovery: Getting this device information Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetState Oct 28 12:36:03 volumio volumio[1161]: info: Listing playlists Oct 28 12:36:03 volumio volumio[1161]: info: CoreCommandRouter::volumioGetQueue Oct 28 12:36:03 volumio volumio[1161]: info: CoreStateMachine::getQueue Oct 28 12:36:03 volumio volumio[1161]: info: CorePlayQueue::getQueue Oct 28 12:36:04 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 28 12:36:21 volumio systemd[1]: Starting apt-daily-upgrade.service - Daily apt upgrade and clean activities... Oct 28 12:36:23 volumio systemd[1]: apt-daily-upgrade.service: Deactivated successfully. Oct 28 12:36:23 volumio systemd[1]: Finished apt-daily-upgrade.service - Daily apt upgrade and clean activities. Oct 28 12:36:23 volumio systemd[1]: apt-daily-upgrade.service: Consumed 1.238s CPU time. Oct 28 12:36:50 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Oct 28 12:36:50 volumio volumio[1161]: info: Saving new wireless network Oct 28 12:36:50 volumio sudo[2319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Oct 28 12:36:50 volumio sudo[2319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:50 volumio sudo[2319]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:50 volumio volumio[1161]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Oct 28 12:36:50 volumio volumio[1161]: info: Discovery: Restarting Advertising due to device name change Oct 28 12:36:50 volumio sudo[2322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Oct 28 12:36:50 volumio sudo[2322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:50 volumio systemd[1]: Stopping wireless.service - Wireless Services... Oct 28 12:36:50 volumio systemd[1]: wireless.service: Deactivated successfully. Oct 28 12:36:50 volumio systemd[1]: Stopped wireless.service - Wireless Services. Oct 28 12:36:50 volumio systemd[1]: wireless.service: Consumed 4min 43.271s CPU time. Oct 28 12:36:50 volumio systemd[1]: Starting wireless.service - Wireless Services... Oct 28 12:36:51 volumio volumio[1161]: info: Discovery: A device disappeared from network Oct 28 12:36:51 volumio volumio[1161]: info: Discovery: Device volumio disappeared from network Oct 28 12:36:51 volumio wireless.js[2326]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Oct 28 12:36:51 volumio wireless.js[2326]: WIRELESS.JS: Wired network status changed to: ---connected--- Oct 28 12:36:51 volumio wireless.js[2326]: WIRELESS.JS: Wireless.js initializing wireless flow Oct 28 12:36:51 volumio sudo[2339]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:51 volumio sudo[2339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:51 volumio wireless.js[2326]: WIRELESS.JS: Cleaning previous... Oct 28 12:36:51 volumio sudo[2339]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:51 volumio volumio[1161]: info: Discovery: A device disappeared from network Oct 28 12:36:51 volumio sudo[2349]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Oct 28 12:36:51 volumio sudo[2349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 28 12:36:51 volumio sudo[2349]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:51 volumio sudo[2351]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Oct 28 12:36:51 volumio sudo[2351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 28 12:36:52 volumio sudo[2351]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:52 volumio wireless.js[2326]: WIRELESS.JS: Stopped aP Oct 28 12:36:52 volumio sudo[2375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 28 12:36:52 volumio sudo[2375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:52 volumio sudo[2372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:52 volumio sudo[2372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:52 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 28 12:36:52 volumio sudo[2375]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:52 volumio sudo[2372]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:52 volumio sudo[2378]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Oct 28 12:36:52 volumio sudo[2378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:52 volumio sudo[2378]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:52 volumio sudo[2386]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 28 12:36:52 volumio sudo[2386]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:52 volumio sudo[2386]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:52 volumio sudo[2388]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Oct 28 12:36:52 volumio sudo[2388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:53 volumio sudo[2393]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:53 volumio sudo[2393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:53 volumio sudo[2393]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:54 volumio sudo[2396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:54 volumio sudo[2396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:54 volumio sudo[2396]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:55 volumio sudo[2388]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:55 volumio wireless.js[2326]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: DE Oct 28 12:36:55 volumio sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Oct 28 12:36:55 volumio sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:55 volumio sudo[2400]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:55 volumio sudo[2402]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Oct 28 12:36:55 volumio sudo[2402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:55 volumio sudo[2402]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:55 volumio wireless.js[2326]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: DE Oct 28 12:36:55 volumio wireless.js[2326]: WIRELESS.JS: Single Network Mode: Wired network active, not starting wireless flow Oct 28 12:36:55 volumio volumio[1161]: info: Discovery: Started advertising with name: Volumio Oct 28 12:36:55 volumio wireless.js[2326]: WIRELESS.JS: Notified systemd about wireless ready Oct 28 12:36:55 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Oct 28 12:36:55 volumio systemd[1]: Started wireless.service - Wireless Services. Oct 28 12:36:55 volumio sudo[2322]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:55 volumio sudo[2410]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:55 volumio sudo[2410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:55 volumio sudo[2410]: pam_unix(sudo:session): session closed for user root Oct 28 12:36:56 volumio volumio[1161]: compat.c: read() failed: Resource temporarily unavailable Oct 28 12:36:56 volumio volumio[1161]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 12:36:56 volumio sudo[2414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 28 12:36:56 volumio sudo[2414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 28 12:36:56 volumio volumio[1161]: Error: dns service error: unknown Oct 28 12:36:56 volumio volumio[1161]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Oct 28 12:36:56 volumio volumio[1161]: errorCode: -65537 Oct 28 12:36:56 volumio volumio[1161]: } Oct 28 12:36:56 volumio volumio[1161]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 28 12:36:56 volumio sudo[2414]: pam_unix(sudo:session): session closed for user root Oct 28 12:37:00 volumio sudo[2431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-28 12:35' Oct 28 12:37:00 volumio sudo[2431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="5ef3d56f987d109f3e21bfa246dbbb723cf6a917" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="c7bff9654d2984a81c5720476c2c8ac531869c54" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Oct 9 18:08:11 UTC 2025" VOLUMIO_VERSION="4.062" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="00524295c246b7d72f125e4c54b86a88"