Device disappeared from network

I am using Volumio version 2.175 on Raspberry PI3. PI3 connect to external DAC through i2S. I have chosen Generic i2S DAC and play song through upnp. The song stopped randomly. I can resume by press play button again. Following is the volumio log file. Seems device disappear from network. Everyone can help?

2017-05-22T07:52:12.519Z - info: Starting playback through UPNP
2017-05-22T07:52:12.521Z - info: [1495439532520] CoreStateMachine::setConsumeUpdateService mpd
2017-05-22T07:59:03.127Z - info: CALLMETHOD: audio_interface upnp startUpnpPlayback [object Object]
2017-05-22T07:59:03.129Z - info: CoreCommandRouter::executeOnPlugin: upnp , startUpnpPlayback
2017-05-22T07:59:03.130Z - info: Starting playback through UPNP
2017-05-22T07:59:03.131Z - info: [1495439943130] CoreStateMachine::setConsumeUpdateService mpd
2017-05-22T07:59:07.459Z - info: CALLMETHOD: audio_interface upnp startUpnpPlayback [object Object]
2017-05-22T07:59:07.460Z - info: CoreCommandRouter::executeOnPlugin: upnp , startUpnpPlayback
2017-05-22T07:59:07.461Z - info: Starting playback through UPNP
2017-05-22T07:59:07.461Z - info: [1495439947461] CoreStateMachine::setConsumeUpdateService mpd
2017-05-22T09:06:59.975Z - info: mDNS: A device disapperared from network
2017-05-22T09:06:59.977Z - info: mDNS: Device volumio disapperared from network
2017-05-22T09:08:00.622Z - info: mDNS: Found device Volumio
2017-05-22T09:11:22.262Z - info: CoreCommandRouter::volumioGetState
2017-05-22T09:11:22.265Z - info: [1495444282263] CoreStateMachine::getState
2017-05-22T09:11:22.270Z - info:
[1495444282267] ---------------------------- Client requests Volumio state
2017-05-22T09:11:22.275Z - info: [1495444282273] InterfaceWebUI::pushState
2017-05-22T09:11:22.300Z - info: [1495444282297] ------------------------------ 37ms
2017-05-22T09:11:22.326Z - info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
2017-05-22T09:11:22.332Z - info:
[1495444282329] ---------------------------- Client requests Menu Items
2017-05-22T09:11:22.335Z - info: [1495444282333] Listing playlists
2017-05-22T09:11:22.338Z - info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
2017-05-22T09:11:22.385Z - info: [1495444282383] ------------------------------ 54ms
2017-05-22T09:12:11.129Z - info: CoreCommandRouter::getUIConfigOnPlugin
2017-05-22T09:12:11.185Z - info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
2017-05-22T09:12:11.191Z - info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
2017-05-22T09:12:11.195Z - info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
2017-05-22T09:12:11.239Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2017-05-22T09:12:11.249Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2017-05-22T09:12:11.252Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2017-05-22T09:12:11.255Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
2017-05-22T09:12:11.259Z - info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam

Your log doesn’t show anything relevant … you need to find the log entries when your problem occurs.

Problem occurred on version 1.63 and hence I have re-imaged to latest version and retest. I just select several songs and loop to play. The log file isn’t that long. I capture the log once music stopped.

2017-05-22T07:52:12.519Z - info: Starting playback through UPNP
2017-05-22T07:52:12.521Z - info: [1495439532520] CoreStateMachine::setConsumeUp$
2017-05-22T07:59:03.127Z - info: CALLMETHOD: audio_interface upnp startUpnpPlay$
2017-05-22T07:59:03.129Z - info: CoreCommandRouter::executeOnPlugin: upnp , sta$
2017-05-22T07:59:03.130Z - info: Starting playback through UPNP
2017-05-22T07:59:03.131Z - info: [1495439943130] CoreStateMachine::setConsumeUp$
2017-05-22T07:59:07.459Z - info: CALLMETHOD: audio_interface upnp startUpnpPlay$
2017-05-22T07:59:07.460Z - info: CoreCommandRouter::executeOnPlugin: upnp , sta$
2017-05-22T07:59:07.461Z - info: Starting playback through UPNP
2017-05-22T07:59:07.461Z - info: [1495439947461] CoreStateMachine::setConsumeUp$
2017-05-22T09:06:59.975Z - info: mDNS: A device disapperared from network
2017-05-22T09:06:59.977Z - info: mDNS: Device volumio disapperared from network
2017-05-22T09:08:00.622Z - info: mDNS: Found device Volumio

You need to get the logs just before and those after the problem occurs (otherwise you miss relevant messages). You can look at the logs before those you give by typing ‘sudo journalctl -b’ and finding the appropriate time.

Following log was taken when the music stopped. Any help?

May 23 23:01:53 volumio volumio[1190]: info: [1495580513732] ControllerMpd::pushState
May 23 23:01:53 volumio volumio[1190]: info: CoreCommandRouter::servicePushState
May 23 23:01:53 volumio volumio[1190]: info: [1495580513733] CoreStateMachine::syncState
May 23 23:01:53 volumio volumio[1190]: info: [1495580513733] CorePlayQueue::getTrack 0
May 23 23:01:53 volumio volumio[1190]: info: STATE SERVICE {“status”:“stop”,“position”:null,“seek”:null,“duration”:null,“samplerate”:null,“bitdepth”:null,“channels”:null,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:null,“artist”:null,“album”:null,“uri”:null}
May 23 23:01:53 volumio volumio[1190]: info: CURRENT POSITION 0
May 23 23:01:53 volumio volumio[1190]: info: [1495580513756] CoreStateMachine::syncState stateService stop
May 23 23:01:53 volumio volumio[1190]: info: [1495580513757] CoreStateMachine::syncState currentStatus play
May 23 23:01:53 volumio volumio[1190]: info: CURRENT POSITION 0
May 23 23:01:53 volumio volumio[1190]: info: CURRENT POSITION 0
May 23 23:01:53 volumio volumio[1190]: info: END OF QUEUE
May 23 23:01:53 volumio volumio[1190]: info: [1495580513769] CoreStateMachine::pushEmptyState
May 23 23:01:53 volumio volumio[1190]: info: CoreCommandRouter::volumioPushState
May 23 23:01:53 volumio volumio[1190]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 23 23:01:53 volumio volumio[1190]: info: [1495580513772]

Would you please post the entire log on pastebin.com/ or similar, because you’re not showing enough information That way, I can see the log in it’s entirety.

‘sudo journalctl -b > mylog.log’ and post the file ‘mylog.log’ (remove any sensitive information), or use the ‘send log’ feature in Volumio volumio.github.io/docs/User_Man … oting.html

Done. Song stopped around May 23 23:01:01

logs.volumio.org/volumio/b8dHxrr.html

No obvious errors evident in full log either :angry:.

Does this problem occur with the same track or different ones?

problem occurred quite random. Sometimes playing over an hour without any problem.

Is it possible for you to try your setup without UPNP play in order to narrow things down a little?

Edit: problem reproduced with UPNP content from my phone (not a NAS problem). No errors shown in logs, but just before play stops Volumio repeatedly tries to “push” the file:

May 25 08:17:05 volumiokitchen volumio[905]: info: [1495700225279] InterfaceWebUI::pushState May 25 08:17:05 volumiokitchen volumio[905]: info: [1495700225310] ------------------------------ 313ms May 25 08:17:05 volumiokitchen volumio[905]: info: [1495700225312] ------------------------------ 311ms May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:17:05 volumiokitchen volumio[905]: info: Pushing Favourites {"service":"mpd","uri":"http://192.168.2.64:57645/external/audio/media/754.mp3","favourite":false} May 25 08:20:18 volumiokitchen volumio[905]: info: Mpd Status Update: player May 25 08:20:18 volumiokitchen volumio[905]: info: May 25 08:20:18 volumiokitchen volumio[905]: [1495700418521] ---------------------------- MPD announces state update

then 3 minute gap, and Volumio apparently gives up (in my case started playing radio which was already in queue).

Can you raise this as an issue on github.com/volumio/Volumio2/issues please, as a UPNP playback problem?

Yes you are correct. I have tried different input source and no problem encountered. Thank you chsims1