Java CPU usage on Mac after 1.5 update

[tonyw1]

I just updated Serviio from 1.4.1.2 to 1.5 (Mac). It has mostly been a smooth transition, except I now have a constantly running Java process that uses 60-80% CPU at all times. It stops when I unload the LaunchDaemon, and returns when I load it. I'm not talking about the large CPU spikes during library updates, but rather the constant CPU usage when nothing appears to be happening.

Looking at the debug log, this happens every minute:

2015-01-22 15:20:12,562 DEBUG [SearchManager] Committing search index
2015-01-22 15:20:42,566 DEBUG [SearchManager] Committing search index
2015-01-22 15:20:51,532 DEBUG [FeedUpdaterWorker] Checking for new and expired online resources
2015-01-22 15:20:51,532 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2015-01-22 15:21:12,569 DEBUG [SearchManager] Committing search index
2015-01-22 15:21:42,572 DEBUG [SearchManager] Committing search index
2015-01-22 15:21:51,535 DEBUG [FeedUpdaterWorker] Checking for new and expired online resources
2015-01-22 15:21:51,535 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2015-01-22 15:22:12,575 DEBUG [SearchManager] Committing search index
2015-01-22 15:22:42,579 DEBUG [SearchManager] Committing search index
2015-01-22 15:22:51,538 DEBUG [FeedUpdaterWorker] Checking for new and expired online resources
2015-01-22 15:22:51,538 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories

I also see this about every 3 minutes:

2015-01-22 16:12:35,564 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface en0 (en0) and address 192.168.0.100, timeout = 0
2015-01-22 16:12:35,564 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device 26f23a08-b29c-32cb-9e8e-478dc9a82680
2015-01-22 16:12:37,438 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:03:20 (advertisement duration is 1800 sec.)

All of this would seem to be normal, and I can see occasional small CPU spikes when it's happening (and large ones when the library is updating). But that doesn't explain the constant CPU use by the Java process during the times in between when nothing is happening in the log.

[zip]

Where are your shared folders, local disks?

Look at this about Delta scanner: http://wiki.serviio.org/doku.php?id=lib ... _mechanism

What does it say in the log about your shared folders (POLLER vs NATIVE)?

[tonyw1]

All the shared folders are on local disks. One internal, two external.

All entries in the log are labeled NATIVE like this:

2015-01-22 16:20:10,182 INFO [LibraryDeltaScanner] Added repository '/Volumes/GoFlex/Multimedia' to delta scanner (NATIVE)

[tonyw1]

Some more info...

If I turn off "Keep library automatically updated" the Java CPU usage drops down to almost nothing. If I turn it on, the Java CPU use goes back up. It stays up regardless of the "Search for updates of currently shared files" setting.

BTW, each time I make a change I unload and reload the LaunchDaemon. Each time it loads I wait until the CPU spikes caused by startup/library updates have stopped before determining if the overall CPU load drops or stays high. Also, each time I unload it the Java process stops so I know this is Serviio and not some other Java process.

[zip]

Ok, so can you try to remove the shared folders on the external drives to see if it helps? How many files do you have on the external drives?

[tonyw1]

I'll remove the external drive shared folders and report back later. In all folders combined, there are about 100k files, although a large percentage of that is images, text, and other misc files. I only have Serviio set to include audio and video files, if that makes any difference.

In the meantime, I did a little more testing and I found the amount of CPU that v1.5 is using is almost identical to the amount v1.4.1.2 uses. The difference is that the old version only causes the spike during the library update interval that I was able to set in the console. I had it set to 120 minutes, so once every 2 hours my CPU would spike for a few minutes and then return to normal. With 1.5, that CPU spike is constant.

Maybe you could bring back the option of a timed library refresh? That would solve my problem.

[tonyw1]

Ok, I can see now that the CPU usage is directly linked to the number of files in the shared folders. The more I add, whether from internal or external drives, the higher the CPU usage gets. This is the case with both 1.4.1.2 and 1.5. I'm guessing that's just the way the library update process works, and there's not much to be done about it.

So I'd like to ask again if it's possible to bring back the timed library update setting? At least that way I can control how often the CPU spikes occur.

BTW, thanks for the work you do. Despite this one complaint, I really do love Serviio.

[zip]

Can you post (or PM me) detailed log of the server startup? I want to see how many folders are being set up for monitoring, etc.

EDIT: Actually, it looks like on Mac the file scanning is not really native (this the CPU load). i'll try to investigate. https://bitbucket.org/xnejp03/serviio/i ... x-taking-a

[tonyw1]

PM sent. It looks like this is a Mac-specific problem and you're working on a fix. Thanks!

[zip]

Yeah - it's a Mac + Java issue. There are some things I can do in the long term, but I'll try to make it a bit better in the short term too for 1.5

[junovitch]

Hello there. I see the same symptoms on FreeBSD with OpenJDK build 1.8.0_25-b17. Turning off "Keep library automatically updated" solves the problem for me as well and I'm good with that approach for now. Will the polling workaround be available as a tunable option for other OS's as well?

Some details... The Serviio logs do show NATIVE mode but I've kicked off Dtrace to do a bit of analysis and I see that Java is walking all my media directories every 5 seconds. So it certainly sounds like the same underlying issue. On the prior releases I've had the update interval set to every 3 hours so it would be nice to hear if there would still be some support in 1.5.1 for falling back to polling with the ability to set an interval.

2015-01-25 23:59:02,540 INFO [LibraryDeltaScanner] Added repository '/zfs/homedirs/common_media' to delta scanner (NATIVE)
2015-01-25 23:59:02,781 INFO [LibraryDeltaScanner] Added repository '/zfs/homedirs/common_photo_albums' to delta scanner (NATIVE)

[zip]

Yes - it looks like BSD uses the same Polling replacement instead of the native events (Java has not implemented it yet).

I'm planning to do some small changes to the polling (each 1 minute) to see if it works better than the Java built-in polling code. I'm not currently planning to make it configurable (at least via the console) for 1.5.1.

Also, I will add you guys to the beta group, it'd be cool to give some feedback during beta testing to see if we are making any progress.

[junovitch]

Awesome stuff. I appreciate it. I think it does make sense to not clutter the console with it if most platforms work well with the native Java events. Would a system property make sense to force polling? Something like a 'serviio.forcedPollingInterval=##' to trigger it perhaps? Whatever the case, I'll look forward to next beta releases and let you know how it behaves on FreeBSD.

[zip]

yeah, just implemented a system property that overwrites the default 1 minute of polling frequency to whatever you want.

[tonyw1]

I just installed the 1.5.1 update on my Mac and it has fixed the CPU usage problem. The new polling method keeps the library updated. Everything seems to be working fine.

Thanks!