Subsonic vs. Hibernation (on Synology NAS)

[gigon]

Problem Description: I am developing Subsonic packages for Synology Diskstation Nas Systems (which is basically creating install scripts) and have a problem since the first time I got Subsonic running on my Diskstation. As long as Subsonic runs the Diskstation does not hibernate.
Troubleshooting Steps: I tried different scenarios, the problem is definitely caused by Subsonic itself. The most promising topic was setting the java Sync interval to once a day by adding -Djava.util.prefs.syncInterval=86400 to the subsonic.sh, but nothing changes (I found this solution at the serviio forum). The questions I currently have are:

Is there a repetitive access to any file caused by Subsonic? (besides the podcast and Library scan which I set to once a day)
Does anyone else have this problem at other Systems (this error occurs on all Synology devices: x86, ARM, PPC)
Does the java line change anything at all?

Subsonic Version: 4.6 to 4.7
Hardware Platform: Synology Diskstation 211+
Java Memory Limit: 256MB
log file lines:

Code: Select all

/var/log$ vi /usr/syno/synoman/webman/3rdparty/Subsonic/subsonic.log
[2012-12-11 14:50:42,969] INFO DaoHelper - Checking database schema.
[2012-12-11 14:51:08,725] INFO DaoHelper - Done checking database schema.
[2012-12-11 14:51:10,846] INFO MediaScannerService - Automatic media library scanning scheduled to run every 1 day(s), starting at Wed Dec 12 03:00:00 CET 2012
[2012-12-11 14:51:11,483] INFO PodcastService - Automatic Podcast update scheduled to run every 24 hour(s), starting at Tue Dec 11 14:56:11 CET 2012
[2012-12-11 14:51:15,436] WARN NetworkService - Failed to delete port mapping.
net.sbbi.upnp.messages.UPNPResponseException: Detailed error code :403, Detailed error description :Not available Action
        at net.sbbi.upnp.messages.ActionMessageResponseParser.startElement(ActionMessageResponseParser.java:145)
        at org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source)
        at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
        at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
        at net.sbbi.upnp.messages.ActionMessage.service(ActionMessage.java:172)
        at net.sbbi.upnp.impls.InternetGatewayDevice.deletePortMapping(InternetGatewayDevice.java:417)
        at net.sourceforge.subsonic.domain.SBBIRouter.deletePortMapping(SBBIRouter.java:61)
        at net.sourceforge.subsonic.service.NetworkService$PortForwardingTask.execute(NetworkService.java:167)
        at net.sourceforge.subsonic.service.NetworkService$Task.run(NetworkService.java:309)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
- /usr/syno/synoman/webman/3rdparty/Subsonic/subsonic.log 1/41 2%
[2012-12-11 14:50:42,969] INFO DaoHelper - Checking database schema.
[2012-12-11 14:51:08,725] INFO DaoHelper - Done checking database schema.
[2012-12-11 14:51:10,846] INFO MediaScannerService - Automatic media library scanning scheduled to run every 1 day(s), starting at Wed Dec 12 03:00:00 CET 2012
[2012-12-11 14:51:11,483] INFO PodcastService - Automatic Podcast update scheduled to run every 24 hour(s), starting at Tue Dec 11 14:56:11 CET 2012
[2012-12-11 14:51:15,436] WARN NetworkService - Failed to delete port mapping.
net.sbbi.upnp.messages.UPNPResponseException: Detailed error code :403, Detailed error description :Not available Action
        at net.sbbi.upnp.messages.ActionMessageResponseParser.startElement(ActionMessageResponseParser.java:145)
        at org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source)
        at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
        at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
        at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
        at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
        at javax.xml.parsers.SAXParser.parse(SAXParser.java:395)
        at net.sbbi.upnp.messages.ActionMessage.service(ActionMessage.java:172)
        at net.sbbi.upnp.impls.InternetGatewayDevice.deletePortMapping(InternetGatewayDevice.java:417)
        at net.sourceforge.subsonic.domain.SBBIRouter.deletePortMapping(SBBIRouter.java:61)
        at net.sourceforge.subsonic.service.NetworkService$PortForwardingTask.execute(NetworkService.java:167)
        at net.sourceforge.subsonic.service.NetworkService$Task.run(NetworkService.java:309)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

[2012-12-11 14:56:11,483] INFO PodcastService - Starting scheduled Podcast refresh.
[2012-12-11 14:56:11,488] INFO PodcastService - Completed scheduled Podcast refresh.
[2012-12-11 17:03:38,702] INFO VersionService - Resolved local Subsonic version to: 4.7
[2012-12-11 17:03:39,281] INFO VersionService - Resolved latest Subsonic final version to: 4.7
[2012-12-11 17:03:39,282] INFO VersionService - Resolved latest Subsonic beta version to: 4.7.beta3
[2012-12-11 18:22:01,773] INFO CoverArtController - Created thumbnail cache /usr/syno/synoman/webman/3rdparty/Subsonic/thumbs/110
[2012-12-11 18:23:14,800] INFO CoverArtController - Created thumbnail cache /usr/syno/synoman/webman/3rdparty/Subsonic/thumbs/200
[2012-12-11 18:23:43,380] INFO PlayerDao - Created player 2.
[2012-12-11 18:24:11,632] INFO PlayQueueInputStream - admin listening to "Alex Clare - The Lateness Of The Hour/01-Alex Care_-_Up All Night.mp3"
[2012-12-11 18:24:21,396] INFO CoverArtController - Created thumbnail cache /usr/syno/synoman/webman/3rdparty/Subsonic/thumbs/48

[daneren2005]

So I'm pretty much talking out of my ass, but while looking some more information about the db Subsonic uses in general I came across this little nugget:

"By default, a FileDescriptor.sync() call is made every 500 milliseconds on the redo log file. If the machine or the Java process is likely to crash often, you can reduce this down to 20 milliseconds for more frequent sync() calls. You can also specify 0 to force a sync() on each commit. This setting can be changed with "SET FILES WRITE DELAY MILLIS m" or the equivalent connection property."

So the db running something every 500ms seems like a decently likely explanation for the system never going into hibernation. This might or might not be the cause though.