-- Logs begin at Thu 2019-02-14 18:11:59 CST, end at Fri 2025-09-12 10:04:08 CST. -- Sep 12 10:03:21 smsl-n100 volumio[1093]: info: Preload queue cleared Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreStateMachine::ClearQueue Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreStateMachine::stop Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CorePlayQueue::clearPlayQueue Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CorePlayQueue::saveQueue Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushQueue Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CoreStateMachine::addQueueItems Sep 12 10:03:22 smsl-n100 volumio[1093]: info: CorePlayQueue::addQueueItems Sep 12 10:03:22 smsl-n100 volumio[1093]: info: Preload queue cleared Sep 12 10:03:22 smsl-n100 volumio[1093]: info: Adding Item to queue: tidal://mymusic/playlists/az/154fabf9-8002-4a7d-bafe-110c2a1f9a9a Sep 12 10:03:22 smsl-n100 volumio[1093]: info: Exploding uri tidal://mymusic/playlists/az/154fabf9-8002-4a7d-bafe-110c2a1f9a9a in service tidal Sep 12 10:03:27 smsl-n100 volumio[1093]: info: explodeTIDALUri took 4966 milliseconds Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushQueue Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CorePlayQueue::saveQueue Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::updateTrackBlock Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrackBlock Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPlay Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::play index 0 Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::stop Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::play index undefined Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::startPlaybackTimer Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:27 smsl-n100 volumio[1093]: info: [1757642607155] ControllerTidal::clearAddPlayTrack Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Getting stream with soundQuality HI_RES Sep 12 10:03:27 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand stop Sep 12 10:03:27 smsl-n100 volumio[1093]: info: sendMpdCommand stop took 81 milliseconds Sep 12 10:03:27 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand clear Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: sendMpdCommand clear took 23 milliseconds Sep 12 10:03:27 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES" Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: error: updateQueue error: null Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 31ms Sep 12 10:03:27 smsl-n100 volumio[1093]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES" took 25 milliseconds Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 22ms Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 18ms Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 12 10:03:27 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand play Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Sep 12 10:03:27 smsl-n100 volumio[1093]: ---------------------------- MPD announces system playlist update Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Ignoring MPD Status Update Sep 12 10:03:27 smsl-n100 volumio[1093]: error: Upnp client error: Error: This socket has been ended by the other party Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 38ms Sep 12 10:03:27 smsl-n100 volumio[1093]: info: sendMpdCommand play took 24 milliseconds Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 23ms Sep 12 10:03:27 smsl-n100 volumio[1093]: info: ------------------------------ 18ms Sep 12 10:03:27 smsl-n100 volumio[1093]: STREAMING PROXY: Handling url /?data=tidal://song/312699550&soundQuality=HI_RES Sep 12 10:03:27 smsl-n100 volumio[1093]: info: Executing endpoint getStreamUrltidal Sep 12 10:03:27 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 12 10:03:28 smsl-n100 volumio[1093]: info: getStreamUrl took 1224 milliseconds Sep 12 10:03:28 smsl-n100 volumio[1093]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyYzYzODY0MGM5NjBlYmEwOWJhNmY2ZGU2ZGYwYjJmN182MS5tcDQ/0.flac?token=1757646208~MzNlOWY5NjFkNDc4MTYyZGI2MzQ1N2UzZGU4NTZiNThiNzRiMGYxZQ== Sep 12 10:03:29 smsl-n100 volumio[1093]: STREAMING PROXY: Response: 200, length: 29184387 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand clearerror Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 43 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand clearerror Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 81 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand clearerror Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 78 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand clearerror took 56 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 48 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 41 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 220ms Sep 12 10:03:29 smsl-n100 volumio[1093]: info: Sep 12 10:03:29 smsl-n100 volumio[1093]: ---------------------------- MPD announces state update: player Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::getState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand status Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 189 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand clearerror took 174 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand clearerror took 170 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 145 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 143 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 135 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand status took 52 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseState Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 389ms Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 383ms Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 341ms Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 131 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: info: sendMpdCommand playlistinfo took 126 milliseconds Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: ControllerMpd::parseTrackInfo Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ControllerMpd::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::servicePushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CorePlayQueue::getTrack 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":253,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"312699550&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/312699550&soundQuality=HI_RES","trackType":"tidal"} Sep 12 10:03:29 smsl-n100 volumio[1093]: verbose: CURRENT POSITION 0 Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState stateService pause Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::syncState currentStatus stop Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:29 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 419ms Sep 12 10:03:29 smsl-n100 volumio[1093]: info: ------------------------------ 272ms Sep 12 10:03:29 smsl-n100 volumio[1093]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined Sep 12 10:03:29 smsl-n100 volumio[1093]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined Sep 12 10:03:29 smsl-n100 volumio[1093]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined Sep 12 10:03:29 smsl-n100 volumio[1093]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined Sep 12 10:03:38 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioGetState Sep 12 10:03:39 smsl-n100 volumio[1093]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 12 10:03:39 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 12 10:03:39 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Sep 12 10:03:40 smsl-n100 sudo[2290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Sep 12 10:03:40 smsl-n100 sudo[2290]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 sudo[2295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 12 10:03:40 smsl-n100 sudo[2295]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 sudo[2290]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2295]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 12 10:03:40 smsl-n100 sudo[2303]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 sudo[2303]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2309]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Sep 12 10:03:40 smsl-n100 sudo[2309]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 sudo[2309]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 12 10:03:40 smsl-n100 sudo[2316]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Sep 12 10:03:40 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Sep 12 10:03:40 smsl-n100 sudo[2316]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 12 10:03:40 smsl-n100 sudo[2318]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 sudo[2318]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:40 smsl-n100 sudo[2322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Sep 12 10:03:40 smsl-n100 sudo[2322]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:40 smsl-n100 volumio[1093]: info: Executing endpoint metavolumio Sep 12 10:03:40 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 12 10:03:40 smsl-n100 volumio[1093]: STREAMING PROXY: Client dropped request, destroying Sep 12 10:03:41 smsl-n100 volumio[1093]: error: Failed request for metavolumio API Sep 12 10:03:45 smsl-n100 sudo[2322]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:55 smsl-n100 volumio[1093]: info: CALLMETHOD: system_controller network saveDnsSettings [object Object] Sep 12 10:03:55 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: network , saveDnsSettings Sep 12 10:03:55 smsl-n100 sudo[2346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /etc/resolv.conf.tail.tmpl /etc/resolv.conf.tail Sep 12 10:03:55 smsl-n100 sudo[2346]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:55 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Sep 12 10:03:55 smsl-n100 volumio[1093]: info: Discovery: Restarting Advertising due to device name change Sep 12 10:03:55 smsl-n100 sudo[2346]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:55 smsl-n100 sudo[2348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Sep 12 10:03:55 smsl-n100 sudo[2348]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:55 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Sep 12 10:03:55 smsl-n100 volumio[1093]: info: Discovery: Restarting Advertising due to device name change Sep 12 10:03:55 smsl-n100 sudo[2353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ip addr flush dev eth0 Sep 12 10:03:55 smsl-n100 sudo[2353]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:55 smsl-n100 systemd[1]: Stopping Wireless Services... Sep 12 10:03:55 smsl-n100 wpa_supplicant[901]: wlan0: CTRL-EVENT-DISCONNECTED bssid=f6:ca:e7:5a:2c:92 reason=3 locally_generated=1 Sep 12 10:03:55 smsl-n100 dhcpcd[556]: wlan0: carrier lost Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Withdrawing address record for 192.168.1.108 on eth0. Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.108. Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: pid 2360 deleted IP address 192.168.1.108/24 Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: deleting route to 192.168.1.0/24 Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: deleting default route via 192.168.1.1 Sep 12 10:03:55 smsl-n100 sudo[2353]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Interface eth0.IPv4 no longer relevant for mDNS. Sep 12 10:03:55 smsl-n100 wpa_supplicant[901]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Sep 12 10:03:55 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:03:55 smsl-n100 volumio[1093]: info: Discovery: A device disappeared from network Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Interface wlan0.IPv4 no longer relevant for mDNS. Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.110. Sep 12 10:03:55 smsl-n100 wpa_supplicant[901]: wlan0: CTRL-EVENT-TERMINATING Sep 12 10:03:55 smsl-n100 avahi-daemon[503]: Withdrawing address record for 192.168.1.110 on wlan0. Sep 12 10:03:55 smsl-n100 systemd[1]: wireless.service: Succeeded. Sep 12 10:03:55 smsl-n100 systemd[1]: Stopped Wireless Services. Sep 12 10:03:55 smsl-n100 volumio[1093]: info: Discovery: A device disappeared from network Sep 12 10:03:55 smsl-n100 sudo[2367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 down Sep 12 10:03:55 smsl-n100 sudo[2367]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:55 smsl-n100 systemd[1]: Starting Wireless Services... Sep 12 10:03:55 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 10:03:55 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: Link is Down Sep 12 10:03:55 smsl-n100 sudo[2367]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:55 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:03:55 smsl-n100 sudo[2393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 up Sep 12 10:03:55 smsl-n100 sudo[2393]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:55 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: PHY [stmmac-0:01] driver [Generic PHY] Sep 12 10:03:55 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: No Safety Features support found Sep 12 10:03:55 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: PTP not supported by HW Sep 12 10:03:55 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: configuring for phy/rgmii link mode Sep 12 10:03:55 smsl-n100 sudo[2393]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:55 smsl-n100 dhcpcd[556]: wlan0: deleting route to 192.168.1.0/24 Sep 12 10:03:55 smsl-n100 dhcpcd[556]: wlan0: deleting default route via 192.168.1.1 Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: rebinding lease of 192.168.1.108 Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: if_sendraw: Network is down Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: carrier lost Sep 12 10:03:55 smsl-n100 dhcpcd[556]: dhcp_readpacket: eth0: Network is down Sep 12 10:03:55 smsl-n100 dhcpcd[556]: arp_read: eth0: Network is down Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: pid 2360 deleted IP address 192.168.1.108/24 Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: deleting route to 192.168.1.0/24 Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: deleting default route via 192.168.1.1 Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: carrier acquired Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: IAID be:ea:27:3d Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: rebinding lease of 192.168.1.108 Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: carrier lost Sep 12 10:03:55 smsl-n100 dhcpcd[980]: eth0: soliciting an IPv6 router Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: carrier acquired Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: IAID be:ea:27:3d Sep 12 10:03:55 smsl-n100 dhcpcd[556]: eth0: soliciting an IPv6 router Sep 12 10:03:56 smsl-n100 ifplugd(eth0)[761]: Link beat lost. Sep 12 10:03:56 smsl-n100 dhcpcd[980]: eth0: carrier lost Sep 12 10:03:56 smsl-n100 dhcpcd[556]: eth0: carrier lost Sep 12 10:03:56 smsl-n100 wireless.js[2381]: Cleaning previous... Sep 12 10:03:56 smsl-n100 sudo[2517]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 12 10:03:56 smsl-n100 sudo[2517]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:56 smsl-n100 sudo[2517]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:56 smsl-n100 sudo[2519]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 12 10:03:56 smsl-n100 sudo[2519]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:56 smsl-n100 sudo[2519]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:56 smsl-n100 wireless.js[2381]: Stopped aP Sep 12 10:03:56 smsl-n100 sudo[2526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 12 10:03:56 smsl-n100 sudo[2526]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:56 smsl-n100 sudo[2526]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:56 smsl-n100 sudo[2528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Sep 12 10:03:56 smsl-n100 sudo[2528]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:56 smsl-n100 sudo[2528]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:56 smsl-n100 sudo[2535]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Sep 12 10:03:56 smsl-n100 sudo[2535]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:56 smsl-n100 sudo[2535]: pam_unix(sudo:session): session closed for user root Sep 12 10:03:57 smsl-n100 sudo[2537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Sep 12 10:03:57 smsl-n100 sudo[2537]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:03:57 smsl-n100 dhcpcd[556]: wlan0: carrier acquired Sep 12 10:03:57 smsl-n100 dhcpcd[556]: wlan0: IAID 2b:ee:c9:e2 Sep 12 10:03:57 smsl-n100 dhcpcd[556]: wlan0: rebinding lease of 192.168.1.110 Sep 12 10:03:57 smsl-n100 dhcpcd[556]: wlan0: soliciting an IPv6 router Sep 12 10:03:58 smsl-n100 ntpd[1082]: Deleting interface #3 eth0, 192.168.1.108#123, interface stats: received=206, sent=206, dropped=4, active_time=342 secs Sep 12 10:03:58 smsl-n100 ntpd[1082]: 123.204.232.128 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.215 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.221 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.212 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.222 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.219 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 17.253.116.253 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.214 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.147.22.149 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.213 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 220.134.160.116 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.217 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.220 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 112.104.189.124 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.211 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.223 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: 103.186.118.218 local addr 192.168.1.108 -> Sep 12 10:03:58 smsl-n100 ntpd[1082]: Deleting interface #4 wlan0, 192.168.1.110#123, interface stats: received=0, sent=0, dropped=0, active_time=342 secs Sep 12 10:03:59 smsl-n100 volumio[1093]: info: Reporting MCU Network Status: 0 Sep 12 10:03:59 smsl-n100 volumio[1093]: info: Volumio Network Manager: Network status updated: 0 Sep 12 10:03:59 smsl-n100 volumio[1093]: info: CoreStateMachine::pushState Sep 12 10:03:59 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 12 10:03:59 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioPushState Sep 12 10:03:59 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output update for this device Sep 12 10:03:59 smsl-n100 volumio[1093]: info: MRS: Pushing multiroomSync output Sep 12 10:03:59 smsl-n100 volumio[1093]: error: Serial API: Failed to decode command: 100, message: undefined Sep 12 10:03:59 smsl-n100 volumio[1093]: error: Serial API: Failed to decode command: MAXVOL, message: Sep 12 10:03:59 smsl-n100 volumio[1093]: error: Serial API: Failed to decode command: 100, message: undefined Sep 12 10:03:59 smsl-n100 volumio[1093]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Sep 12 10:03:59 smsl-n100 volumio[1093]: error: Serial API: Failed to decode command: 0, message: undefined Sep 12 10:04:00 smsl-n100 volumio[1093]: info: Discovery: Started advertising with name: SMSL N100 Sep 12 10:04:00 smsl-n100 volumio[1093]: info: Discovery: Started advertising with name: SMSL N100 Sep 12 10:04:00 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx Sep 12 10:04:00 smsl-n100 dhcpcd[980]: eth0: carrier acquired Sep 12 10:04:00 smsl-n100 dhcpcd[556]: eth0: carrier acquired Sep 12 10:04:00 smsl-n100 dhcpcd[980]: eth0: IAID be:ea:27:3d Sep 12 10:04:00 smsl-n100 dhcpcd[556]: eth0: IAID be:ea:27:3d Sep 12 10:04:00 smsl-n100 dhcpcd[980]: eth0: soliciting an IPv6 router Sep 12 10:04:00 smsl-n100 dhcpcd[980]: eth0: rebinding lease of 192.168.1.108 Sep 12 10:04:00 smsl-n100 dhcpcd[980]: eth0: probing address 192.168.1.108/24 Sep 12 10:04:00 smsl-n100 dhcpcd[556]: eth0: rebinding lease of 192.168.1.108 Sep 12 10:04:01 smsl-n100 dhcpcd[556]: eth0: probing address 192.168.1.108/24 Sep 12 10:04:01 smsl-n100 ifplugd(eth0)[761]: Link beat detected. Sep 12 10:04:01 smsl-n100 sudo[2537]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:01 smsl-n100 wireless.js[2381]: Start wireless flow Sep 12 10:04:01 smsl-n100 wireless.js[2381]: Stopped hotspot (if there).. Sep 12 10:04:01 smsl-n100 dhcpcd[556]: eth0: soliciting an IPv6 router Sep 12 10:04:01 smsl-n100 sudo[2561]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Sep 12 10:04:01 smsl-n100 sudo[2561]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:01 smsl-n100 sudo[2561]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:01 smsl-n100 sudo[2563]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Sep 12 10:04:01 smsl-n100 sudo[2563]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:01 smsl-n100 dhcpcd[556]: wlan0: carrier lost Sep 12 10:04:01 smsl-n100 sudo[2563]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:01 smsl-n100 wireless.js[2381]: DHCP IP Sep 12 10:04:01 smsl-n100 wireless.js[2381]: Start ap Sep 12 10:04:01 smsl-n100 wpa_supplicant[2568]: Successfully initialized wpa_supplicant Sep 12 10:04:01 smsl-n100 sudo[2572]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Sep 12 10:04:01 smsl-n100 sudo[2572]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:01 smsl-n100 dhcpcd[2580]: sending commands to master dhcpcd process Sep 12 10:04:01 smsl-n100 sudo[2572]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:01 smsl-n100 dhcpcd[556]: control command: /sbin/dhcpcd Sep 12 10:04:01 smsl-n100 dhcpcd[556]: wlan0: carrier acquired Sep 12 10:04:01 smsl-n100 dhcpcd[556]: wlan0: IAID 2b:ee:c9:e2 Sep 12 10:04:01 smsl-n100 dhcpcd[556]: wlan0: carrier lost Sep 12 10:04:02 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:02 smsl-n100 sudo[2594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:02 smsl-n100 sudo[2594]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:02 smsl-n100 sudo[2594]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:03 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:03 smsl-n100 sudo[2597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:03 smsl-n100 sudo[2597]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:03 smsl-n100 sudo[2597]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:04 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:04 smsl-n100 sudo[2602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:04 smsl-n100 sudo[2602]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:04 smsl-n100 sudo[2602]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:05 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Sep 12 10:04:05 smsl-n100 volumio[1093]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Sep 12 10:04:05 smsl-n100 volumio[1093]: info: Refreshing Cached IP Addresses Sep 12 10:04:05 smsl-n100 sudo[2606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Sep 12 10:04:05 smsl-n100 sudo[2606]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:05 smsl-n100 sudo[2606]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:05 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:05 smsl-n100 sudo[2609]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 12 10:04:05 smsl-n100 sudo[2609]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:05 smsl-n100 sudo[2609]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:05 smsl-n100 sudo[2611]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 12 10:04:05 smsl-n100 sudo[2611]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:05 smsl-n100 systemd[1]: upmpdcli.service: Succeeded. Sep 12 10:04:05 smsl-n100 sudo[2614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:05 smsl-n100 sudo[2611]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:05 smsl-n100 sudo[2614]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:05 smsl-n100 sudo[2614]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:06 smsl-n100 dhcpcd[980]: eth0: leased 192.168.1.108 for 86400 seconds Sep 12 10:04:06 smsl-n100 dhcpcd[980]: eth0: adding route to 192.168.1.0/24 Sep 12 10:04:06 smsl-n100 avahi-daemon[503]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.108. Sep 12 10:04:06 smsl-n100 dhcpcd[980]: eth0: adding default route via 192.168.1.1 Sep 12 10:04:06 smsl-n100 avahi-daemon[503]: New relevant interface eth0.IPv4 for mDNS. Sep 12 10:04:06 smsl-n100 avahi-daemon[503]: Registering new address record for 192.168.1.108 on eth0.IPv4. Sep 12 10:04:06 smsl-n100 ntpd[1082]: ntpd exiting on signal 15 (Terminated) Sep 12 10:04:06 smsl-n100 systemd[1]: Stopping Network Time Service... Sep 12 10:04:06 smsl-n100 systemd[1]: ntp.service: Succeeded. Sep 12 10:04:06 smsl-n100 systemd[1]: Stopped Network Time Service. Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 10:04:06 smsl-n100 systemd[1]: Starting Network Time Service... Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:04:06 smsl-n100 ntpd[2651]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 12 10:04:06 smsl-n100 ntpd[2651]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 12 10:04:06 smsl-n100 systemd[1]: Started Network Time Service. Sep 12 10:04:06 smsl-n100 ntpd[2657]: proto: precision = 1.166 usec (-20) Sep 12 10:04:06 smsl-n100 ntpd[2657]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 12 10:04:06 smsl-n100 ntpd[2657]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 12 10:04:06 smsl-n100 ntpd[2657]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 990 days ago Sep 12 10:04:06 smsl-n100 ntpd[2657]: Listen and drop on 0 v6wildcard [::]:123 Sep 12 10:04:06 smsl-n100 ntpd[2657]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 12 10:04:06 smsl-n100 ntpd[2657]: Listen normally on 2 lo 127.0.0.1:123 Sep 12 10:04:06 smsl-n100 ntpd[2657]: Listen normally on 3 eth0 192.168.1.108:123 Sep 12 10:04:06 smsl-n100 ntpd[2657]: Listening on routing socket on fd #20 for interface updates Sep 12 10:04:06 smsl-n100 ntpd[2657]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 12 10:04:06 smsl-n100 ntpd[2657]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 12 10:04:06 smsl-n100 dhcpcd[556]: eth0: leased 192.168.1.108 for 86400 seconds Sep 12 10:04:06 smsl-n100 dhcpcd[556]: eth0: adding route to 192.168.1.0/24 Sep 12 10:04:06 smsl-n100 dhcpcd[556]: eth0: adding default route via 192.168.1.1 Sep 12 10:04:06 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:06 smsl-n100 sudo[2688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:06 smsl-n100 sudo[2688]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:06 smsl-n100 sudo[2688]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:06 smsl-n100 ntpd[2657]: ntpd exiting on signal 15 (Terminated) Sep 12 10:04:06 smsl-n100 systemd[1]: Stopping Network Time Service... Sep 12 10:04:06 smsl-n100 systemd[1]: ntp.service: Succeeded. Sep 12 10:04:06 smsl-n100 systemd[1]: Stopped Network Time Service. Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:04:06 smsl-n100 systemd[1]: Starting Network Time Service... Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Sep 12 10:04:06 smsl-n100 volumio[1093]: ------------------------------------ BT MESSAGE: BT STATUS: running Sep 12 10:04:06 smsl-n100 ntpd[2693]: ntpd 4.2.8p12@1.3728-o (1): Starting Sep 12 10:04:06 smsl-n100 ntpd[2693]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Sep 12 10:04:06 smsl-n100 systemd[1]: Started Network Time Service. Sep 12 10:04:06 smsl-n100 ntpd[2699]: proto: precision = 1.166 usec (-20) Sep 12 10:04:06 smsl-n100 ntpd[2699]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Sep 12 10:04:06 smsl-n100 ntpd[2699]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Sep 12 10:04:06 smsl-n100 ntpd[2699]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 990 days ago Sep 12 10:04:06 smsl-n100 ntpd[2699]: Listen and drop on 0 v6wildcard [::]:123 Sep 12 10:04:06 smsl-n100 ntpd[2699]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Sep 12 10:04:06 smsl-n100 ntpd[2699]: Listen normally on 2 lo 127.0.0.1:123 Sep 12 10:04:06 smsl-n100 ntpd[2699]: Listen normally on 3 eth0 192.168.1.108:123 Sep 12 10:04:06 smsl-n100 ntpd[2699]: Listening on routing socket on fd #20 for interface updates Sep 12 10:04:06 smsl-n100 ntpd[2699]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 12 10:04:06 smsl-n100 ntpd[2699]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Sep 12 10:04:07 smsl-n100 volumio[1093]: info: Discovery: adding 0261ae32-43cb-451b-be0e-dbd56711c524 Sep 12 10:04:07 smsl-n100 volumio[1093]: info: Discovery: Found device SMSL N100 Sep 12 10:04:07 smsl-n100 volumio[1093]: info: CoreCommandRouter::volumioGetState Sep 12 10:04:07 smsl-n100 volumio[1093]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 10:04:07 smsl-n100 volumio[1093]: Error: The value NaN is not a number Sep 12 10:04:07 smsl-n100 volumio[1093]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Sep 12 10:04:07 smsl-n100 volumio[1093]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Sep 12 10:04:07 smsl-n100 volumio[1093]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) Sep 12 10:04:07 smsl-n100 volumio[1093]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Sep 12 10:04:07 smsl-n100 volumio[1093]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Sep 12 10:04:07 smsl-n100 volumio[1093]: at Browser.emit (events.js:400:28) Sep 12 10:04:07 smsl-n100 volumio[1093]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Sep 12 10:04:07 smsl-n100 volumio[1093]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Sep 12 10:04:07 smsl-n100 volumio[1093]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Sep 12 10:04:07 smsl-n100 volumio[1093]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Sep 12 10:04:07 smsl-n100 volumio[1093]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Sep 12 10:04:07 smsl-n100 volumio[1093]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Sep 12 10:04:07 smsl-n100 volumio[1093]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Sep 12 10:04:07 smsl-n100 volumio[1093]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: Trying to associate with f6:ca:e7:5a:2c:92 (SSID='wenmei1F' freq=5785 MHz) Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: Associated with f6:ca:e7:5a:2c:92 Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=TW Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: WPA: Key negotiation completed with f6:ca:e7:5a:2c:92 [PTK=CCMP GTK=CCMP] Sep 12 10:04:07 smsl-n100 wpa_supplicant[2584]: wlan0: CTRL-EVENT-CONNECTED - Connection to f6:ca:e7:5a:2c:92 completed [id=0 id_str=] Sep 12 10:04:07 smsl-n100 dhcpcd[556]: wlan0: carrier acquired Sep 12 10:04:07 smsl-n100 dhcpcd[556]: wlan0: IAID 2b:ee:c9:e2 Sep 12 10:04:07 smsl-n100 wireless.js[2381]: trying... Sep 12 10:04:07 smsl-n100 dhcpcd[556]: wlan0: rebinding lease of 192.168.1.110 Sep 12 10:04:07 smsl-n100 sudo[2713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Sep 12 10:04:07 smsl-n100 sudo[2713]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:07 smsl-n100 sudo[2713]: pam_unix(sudo:session): session closed for user root Sep 12 10:04:07 smsl-n100 dhcpcd[556]: wlan0: probing address 192.168.1.110/24 Sep 12 10:04:08 smsl-n100 sudo[2716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-12 10:03 Sep 12 10:04:08 smsl-n100 sudo[2716]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 12 10:04:08 smsl-n100 dhcpcd[556]: wlan0: soliciting an IPv6 router PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="723ba1d50268911818ebdca474fb7656df6050cb" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="smsl" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 14 Feb 2025 02:46:15 PM CET" VOLUMIO_VERSION="3.789" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR_MODEL="SMSL S100" VOLUMIO_VENDOR="SMSL" VOLUMIO_MODEL="S100" VOLUMIO_HASH="215d731aee688e00fb3cc923952be9a7"