Page 1 of 2

Using Android App Causes subsonic-service.exe to 100% CPU

PostPosted: Thu Jul 22, 2010 2:15 pm
by blinkfink182
Firstly, absolutely love Subsonic, it is a wonderful setup, and I donated because of that! :D

However, I am having a problem when trying to use the Android app. Basically I can get as far as trying to pull up an album's songs (pulling up artists & their albums usually works fine) or long-pressing the album and hitting play, then (assuming the songs aren't cached) I get a network error. There isn't a network issue since accessing Subsonic via the web interface works fine and without issue. So I check the server and I see the subsonic-service.exe process (I'm on Windows Server 2008) is now eating as much CPU as possible (usually around 75% or higher) and slows down other services I run on the same server.

Anyone else run into this or any ideas what can be causing this? I'm using the latest versions of both the Subsonic server and the Android app.

PostPosted: Thu Jul 22, 2010 2:19 pm
by blinkfink182
Forgot to add that the CPU whoring doesn't stop until I stop Subsonic and restart it.

PostPosted: Fri Jul 23, 2010 2:43 am
by gravelhead44
This has just started happening for me as well. It was working fine, then just yesterday it started to use up a lot of memory on my server. Using Ubuntu server 9.04.

The only thing I know has changed is upgrading to the new android client.

PostPosted: Fri Jul 23, 2010 11:54 pm
by blinkfink182
No memory issues on the server, just cpu usage spiking.

PostPosted: Sat Jul 24, 2010 3:43 am
by gravelhead44
I uninstalled and reinstalled, now all is well. Appears it was all a coincidence for me.

CPU utilization

PostPosted: Mon Jul 26, 2010 11:03 am
by tguless
I am having the same issue. Subsonic used to work great, it recently started taking up a big chunk of CPU utilization. Reinstalling the server did not make a difference for me.

PostPosted: Mon Jul 26, 2010 2:14 pm
by blinkfink182
I did try uninstalling and reinstalling and it did not help. Even installed to a whole new directory/drive to make sure it wasn't anything strange with that.

Noticed that a request keeps getting sent to the server...

PostPosted: Wed Jul 28, 2010 5:03 pm
by tguless
I noticed that a request keeps getting sent from the android app to the server over and over again until the server stops responding.

This is especially the case if your server is running slow because of the SAMBA issue when you serve your music from a NAS.

I intercepted the request by putting in a ProxyPass directive inside my apache instance:

ProxyPass "/subsonic/" "http://localhost:4040/subsonic/"
ProxyPassReverse "/subsonic/" "http://localhost:4040/subsonic/"


and then looking at my apache logs:
less /var/log/apache2/access.log

This is what the request shows:
GET /subsonic/rest/getRandomSongs.view?u=admin&p=enc:686169673234&v=1.2.0&c=android&size=100

This request takes 65 seconds to come back on my Ubuntu instance with this db size:

4,088 artists
3,609 albums
27,020 songs
134.36 GB (~ 2,087 hours)

And these are the frequency of request coming in from the Android app.
[26/Jul/2010:11:36:15 -0400]
[26/Jul/2010:11:36:28 -0400]
[26/Jul/2010:11:36:40 -0400]
[26/Jul/2010:11:36:53 -0400]
[26/Jul/2010:11:37:05 -0400]

The app effectively does a DDOS attack on my server and brings the whole machine to a crawl.

This is with one android app accessing subsonic, if you increase the number of clients, the frequency you see above doubles and the server goes down in a minute.

I emailed the developer a few days back, I did not get a response.

Here is my original email:

-----Original Message-----
From: Gulesserian, Ted
Sent: Monday, July 26, 2010 7:26 PM
To: sindre@activeobjects.no
Subject: Subsonic Music Streamer

Hello, your latest app keeps making an http request to the server for random songs and effectively causin a denial of service attack. I have to keep restarting the server. The timeout period should be configurable for those of us that don't have beefy machines.

Otherwise I love the app.

Thanks, Ted

PostPosted: Wed Jul 28, 2010 5:14 pm
by blinkfink182
tguless: Does that request show up in the subsonic logs at all? I'd like to confirm that's the same issue I'm having.

It does not show up in the logs...

PostPosted: Wed Jul 28, 2010 6:51 pm
by tguless
That's why I had to use the ProxyPass trick to get an audit and figure out why the Java process was inching up closer to the 100% mark every second.

Incidentally, I got my server working again by
a) Grabbing a static copy of getRandomSongs.view.xml (after waiting 65 seconds for it to generate).
b) Adding a link to the static file in the apache config file "/etc/apache2/apache2.conf" when the request for the getRandomSongs.view comes in

Here are the additions I did to apache2.conf, this supplements my previous ProxyPass additions I posted:

ProxyPass "/subsonic/rest/getRandomSongs.view" "http://localhost/getRandomSongs.view.xml"
ProxyPassReverse "/subsonic/rest/getRandomSongs.view" "http://localhost/getRandomSongs.view.xml"

Note that I dropped the static file in the root of my webserver. Now the script completes instantaneously by serving this static file and doesn't tie up the server.

The real solution is to figure out why Subsonic and Samba aren't mixing well. I have the same issue on windows and Ubuntu with Samba. If it is just a matter of the slow performance of Samba, then either a caching mechanism is needed (like when the nightly search index is created, the cache also gets generated), or some functions in the android app should not time out so quickly. Retries of these timed out scripts (possibly from various phones) are DDoSing the server.

I am going to explore using the USB interface on my NAS to avoid Samba, but the NAS only allows Samba sharing and unless I jailbreak the firmware and get crazy with getting NFS working, I am still stuck with awful performance. Keeping fingers crossed for the USB trick.

I hope all this helps.

Ted

Here is the link to the slow Samba issue...

PostPosted: Wed Jul 28, 2010 6:54 pm
by tguless

PostPosted: Wed Jul 28, 2010 6:58 pm
by blinkfink182
Wow, thanks for all that man, really appreciated. I'm sure that's what's happening on mine because I'm also serving off of a NAS. Hopefully this gets fixed soon so I can justify my donation. ;)

PostPosted: Wed Jul 28, 2010 9:32 pm
by blinkfink182
One more quick question for you: Does that XML file only get generated if you try to use the "Random" menu entry in the Android app? Or does it try to generate it no matter what? If I can just avoid using the "Random" menu entry, then I can certainly live with that.

PostPosted: Wed Jul 28, 2010 10:14 pm
by tguless
Not sure what is causing it to get triggered - but I found where in the code it is getting stuck.

Lines 501 - 507 in
net\sourceforge\subsonic\controller\RESTController.java

LOG.info("Before searchService");
for (MusicFile musicFile : searchService.getRandomSongs(criteria)) {
List<File> coverArt = musicFileService.getCoverArt(musicFile.getParent(), 1);
List<Attribute> attributes = createAttributesForMusicFile(player, coverArt, musicFile);
builder.add("song", attributes, true);
}
LOG.info("After searchService");

The searchService.getRandomSongs(criteria) call comes back fast, so it's not the culprit. The loop above that is trying to get coverart information is what bogs down the call.

Maybe we can comment it out for now?

Here are the metrics on this loop:
[2010-07-28 17:59:37,792] INFO RESTController - Before searchService
[2010-07-28 17:59:37,793] INFO SearchService - begin getIndex()
[2010-07-28 17:59:37,793] INFO SearchService - end getIndex()
[2010-07-28 17:59:37,793] INFO SearchService - begin iterationLoop()
[2010-07-28 17:59:45,426] INFO SearchService - end iterationLoop()
[2010-07-28 18:00:49,353] INFO RESTController - After searchService

The Coverart data population loop above is taking a whopping 72 seconds. That's where the optimization should be focused.

PostPosted: Wed Jul 28, 2010 11:07 pm
by tguless
Ok I did the following changes to net\sourceforge\subsonic\controller\RESTController.java to temporarily disable the coverart lookup for /subsonic/rest/getRandomSongs.view call.

LOG.info("Before searchService");
for (MusicFile musicFile : searchService.getRandomSongs(criteria)) {
//List<File> coverArt = musicFileService.getCoverArt(musicFile.getParent(), 1);
List<File> coverArt = new ArrayList<File>();
//musicFileService.getCoverArt(musicFile.getParent(), 1);
List<Attribute> attributes = createAttributesForMusicFile(player, coverArt, musicFile);
builder.add("song", attributes, true);
}
LOG.info("After searchService");

You can grab the affected compiled files at the following URLs:

http://edgewater.homeip.net/misc/RESTController$1.class
http://edgewater.homeip.net/misc/RESTCo ... Code.class
http://edgewater.homeip.net/misc/RESTController.class

Just replace yours at
/var/subsonic/jetty/1524/webapp/WEB-INF/classes/net/sourceforge/subsonic/controller
on Ubuntu or
C:\subsonic\jetty\1529\webapp\WEB-INF\classes\net\sourceforge\subsonic\controller
on Windows

Good luck.