MiniDLNA crashes after 6 hours

[SebZab]

I have got miniDLNA running on Entware. USB HDD is connected to AC56U working as AP client. After 6h media server crash and stop to be visible in network. I see in logs that this is connected with dnsmasq service each 6h. When dnsmasq start, dlna service crashes.

minidlna.log:
[2015/06/01 17:21:15] minidlna.c:1026: warn: Starting MiniDLNA version 1.1.4.
[2015/06/01 17:21:15] minidlna.c:357: warn: New media_dir detected; rescanning...
[2015/06/01 17:21:15] minidlna.c:1065: warn: HTTP listening on port 8200
[2015/06/01 17:21:15] scanner.c:726: warn: Scanning /tmp/mnt/Seagate/media
[2015/06/01 17:26:14] scanner.c:813: warn: Scanning /tmp/mnt/Seagate/media finished (789 files)!
[2015/06/01 17:26:14] playlist.c:125: warn: Parsing playlists...
[2015/06/01 17:26:14] playlist.c:259: warn: Finished parsing playlists.
[2015/06/01 23:21:08] minidlna.c:154: warn: received signal 15, good-bye

syslog.log:
Jun 1 20:59:21 sd-idle-2.6[464]: spinning down /dev/sda after 1 hours 1 mins
Jun 1 21:04:51 sd-idle-2.6[464]: spinning up /dev/sda after 5 mins 30 secs
Jun 1 21:36:21 sd-idle-2.6[464]: spinning down /dev/sda after 31 mins 30 secs
Jun 1 23:21:06 rc_service: udhcpc_lan 1311:notify_rc start_dnsmasq
Jun 1 23:21:08 rc_service: udhcpc_lan 1311:notify_rc restart_dms
Jun 1 23:21:21 sd-idle-2.6[464]: spinning up /dev/sda after 1 hours 45 mins
Jun 1 23:51:51 sd-idle-2.6[464]: spinning down /dev/sda after 30 mins 30 secs
Jun 2 01:21:52 sd-idle-2.6[464]: spinning up /dev/sda after 1 hours 30 mins 1 secs
Jun 2 01:52:52 sd-idle-2.6[464]: spinning down /dev/sda after 31 mins
Jun 2 05:21:09 rc_service: udhcpc_lan 1484:notify_rc start_dnsmasq
Jun 2 05:21:11 rc_service: udhcpc_lan 1484:notify_rc restart_dms
Jun 2 05:57:52 sd-idle-2.6[464]: spinning up /dev/sda after 4 hours 5 mins

 

[SebZab]

Update: problem is caused not by 'dnsmasq' but by 'restart_dms'.
When I run command: services restart_dms my DLNA server stop working.
I suspect that this command reffer to stock media server which is disabled because I'm running mindlna from Entware.
Any ideas how to resolve it ?

 

[RMerlin]

Update: problem is caused not by 'dnsmasq' but by 'restart_dms'.
When I run command: services restart_dms my DLNA server stop working.
I suspect that this command reffer to stock media server which is disabled because I'm running mindlna from Entware.
Any ideas how to resolve it ?

Try renaming the minidlna executable to a different name (for example dlna), to ensure the router won't be killing it.

 

[SebZab]

Thanks, renaming minidlna helped!

 

[SebZab]

Update:
Renaming minidlna helps but only when I run in SSH command "service restart_dms".

When router executes this command themself each 6 hour, stock miniDLNA server crashes and stop working.

It's happen exactly when the line "rc_service: udhcpc_lan 1311:notify_rc restart_dms" occurs in log file.

Something more than only restarting dms must be the reason of this.

 

[ASAT]

Check this property value:

nvram get dms_rescan

If it's set to 1, try setting it to 0:

nvram set dms_rescan=0 && nvram commit && service restart_dms

I'm just guessing this.

 

[SebZab]

I found the reason.
If I enable hdd spin down option in Window's Seagate Dashboard utility above described problem occurs.
When hdd spin down is disable - miniDLNA server works all the time properly, but HDD never goes sleep.
It's looks like Seagate's own power management tool cause too deep sleeping mode for miniDLNA. It's strange because other services like FTP, SMB are waking up properly. I'm using this option from Seagate because Asus built-in power off utility doesn't work with my hdd.
Another strange thing is that Seagate's power off tool works properly when I use miniDLNA installed in Entware instead of stock one.

Going deep and deep into this subject I discovered that proces which push command 'restart_dms' each 6h is in file 'lan.c'

#ifdef RTCONFIG_USB
#ifdef RTCONFIG_MEDIA_SERVER
    if(get_invoke_later()&INVOKELATER_DMS)
        notify_rc("restart_dms");

Is there some way to disable this command and not to allow router to perform this task ?

 

[SebZab]

I know how to reproduce this error:

1. Open Putty and login (it must be done the first otherwise hdd will spin up if done later)
2. Wait untill hdd will spin down
3. Run command: service start_dnsmasq && service restart_dms
4. Stock miniDLNA should crash

 

[john9527]

Two things.....
(1) I'm not sure what is triggering the restarts? Does your ISP have a short lease time?
(2) In looking at the minidlna code, it looks like there may be a hardcoded 5 sec timeout for accessing the minidlna db. It may be that it is taking longer for your disk to wake up from it's 'deep sleep'

 

[RMerlin]

(2) In looking at the minidlna code, it looks like there may be a hardcoded 5 sec timeout for accessing the minidlna db. It may be that it is taking longer for your disk to wake up from it's 'deep sleep'

5 seconds sounds awfully short, considering we're talking about embedded devices here, not high-power desktops. That might be worth adjusting, unless it's part of some DLNA timing specifications stating that you must reply queries within a certain amount of time.

 

[john9527]

5 seconds sounds awfully short, considering we're talking about embedded devices here, not high-power desktops. That might be worth adjusting, unless it's part of some DLNA timing specifications stating that you must reply queries within a certain amount of time.

I'm doing a test build to make available for him to try if he's game There could always be another timeout that I didn't see....

 

[SebZab]

I haven't got wan in AC56U because it works as AP client wired to TP-LINK router (with USB LTE 4G dongle).

 

[john9527]

I'm doing a test build to make available for him to try if he's game There could always be another timeout that I didn't see....

Well, he tried the test build with the longer timeout with no change, so it's something else

I know how to reproduce this error:

1. Open Putty and login (it must be done the first otherwise hdd will spin up if done later)
2. Wait untill hdd will spin down
3. Run command: service start_dnsmasq && service restart_dms
4. Stock miniDLNA should crash

To see what's really happening, change your test sequence to:
1. Open Putty and login (it must be done the first otherwise hdd will spin up if done later)
2. Wait untill hdd will spin down
3. Run command:
service start_dnsmasq
killall minidlna
minidlna -R -d -f /etc/minidlna.conf

This will start minidlna (dms) in debug mode and start dumping a lot of data to the terminal. Maybe we can see what happens right before it crashes. (if it doesn't exist gracefully on the crash, enter Ctrl-C to end debug mode).

 

[SebZab]

I did all above steps and minidlna worked normally. After scaning db debug ended with lines:

[2015/06/13 21:44:59] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:02] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:47] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:50] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:53] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:56] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:45:59] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"
[2015/06/13 21:46:02] minissdp.c:647: debug: SSDP M-SEARCH from 192.168.0.209:55637 ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1, MX: 3, MAN: "ssdp:discover"

when I pressed ctrl+C debug showed:

^C[2015/06/13 21:46:06] minidlna.c:156: warn: received signal 2, good-bye
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]
[2015/06/13 21:46:13] minissdp.c:743: maxdebug: Sending ssdp:byebye [8]

and minidlna server dissapeared as usually....

 

[john9527]

Oh my.....that's the same thing that happened to me when I debugged a miniupnpd problem with Plex Media Server. Enabling the debug changed the timings enough that the problem went away. But it's interesting, in that the last things happening where not minidlna functions, but minissdp calls.
Have to think about that one a bit.

EDIT: Merlin did a miniupnpd update in 378.54....do you know if you had the problem on .53?

 

[SebZab]

I donwgreded to 378.53 and still the same error