SongKong Jaikoz

SongKong and Jaikoz Music Tagger Community Forum

Gradually increasing CPU usage during AutoCorrect

System: Windows 7 SP1 x64, Java 7u5, Core i7 980X, 12GB RAM

Library size: 75,369 songs, attempting to load and process ~5100 at a time.

Repro:
File - Add Folder
(select the folder containing ~5100 songs)
Allow to load
Hit the AutoCorrect button.

During the MusicBrainz and Discogs stages, it seems like worker threads occasionally hang and spin, causing gradually increased CPU over time (17%, to 42%, to 67%, and finally 100%). This is an example on the console:

16/07/2012 15.02.19:com.jthink.jaikoz.manipulate.musicbrainzhelper.GetBestScorin
gRelease:call:SEVERE: ad9d1798-e8b1-4211-a1a7-b999f6053e04:42
16/07/2012 15.07.18:com.jthink.jaikoz.manipulate.Analyser:waitForWorkers:WARNING
: Timeout waiting for the 86th task to complete
16/07/2012 15.07.24:com.jthink.jaikoz.manipulate.Analyser:waitForWorkers:WARNING
: Cancelled worker:75
16/07/2012 15.07.24:com.jthink.jaikoz.manipulate.musicbrainzhelper.MusicBrainzSc
orer:calculateReleaseScores:WARNING: null
java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
.reportInterruptAfterWait(Unknown Source)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
.await(Unknown Source)
at java.util.concurrent.LinkedBlockingQueue.take(Unknown Source)
at java.util.concurrent.ExecutorCompletionService.take(Unknown Source)
at com.jthink.jaikoz.manipulate.musicbrainzhelper.MusicBrainzScorer.calc
ulateReleaseScores(MusicBrainzScorer.java:1303)
at com.jthink.jaikoz.manipulate.musicbrainzhelper.MusicBrainzScorer.calc
ulateBestReleaseScore(MusicBrainzScorer.java:1065)
at com.jthink.jaikoz.manipulate.CorrectFromMusicBrainzWorker.call(Correc
tFromMusicBrainzWorker.java:295)
at com.jthink.jaikoz.manipulate.CorrectFromMusicBrainzWorker.call(Correc
tFromMusicBrainzWorker.java:36)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)

I am talking to a local MusicBrainz server (on another machine), although it doesn’t seem to matter if I use this server or just musicbrainz.org. This also occurs during Discogs processing.

I’m a new user (just got a Pro license), am I doing something wrong? What else would help to debug? logs? process dump?

Could you send email your support files please (Advanced/Create Suport Files)

Sent. Thanks for the quick response!

Hi your requests are exceeding the allowable rate limit when doing searching causing numerous timeouts. I’m wondering if there is a bug in my code causing a problem because you are using a local search server for lookups but not searches.

Do you have a Pro license ?

If you can set up a local search server and configure it in Jaikoz in Preferences:Musicbrainz:Musicbrainz Server

I do have a Pro license. I’ll work on setting up a search server, but in the interim I have reverted back to using the official http://musicbrainz.org server only. I am still able to repro the problem. I’ll see if I can repro on another machine.

Ok, please send me the latest support file then

Disregard Paul - have elected to distribute the files amongst VM’s and let them each crunch. I’ve found that Jaikoz works really well in Ubuntu 12.04 x64, with the default-jre JVM.

As for the Musicbrainz server - adding the Search Server functionality (per the instructions at http://bugs.musicbrainz.org/browser/search_server/trunk/README) increased performance and got me around the rate limit.

It seems though indeed, if you use a local server for lookups and the “main” Search Server you will potentially hit timeouts/hung threads.

I have an interesting case of CPU utilization as well. I notice that while doing my Autocorrect the utilization rises to 100% and stays there regardless if Jaikoz is doing anything. It could be done with all its processes but utilization stays at 100% until I close the program.

I will send in my support files for reference.

same here, but without prospect for completion

when checking release groups (step 1) it stops processing half way (no noticeable progress anymore), at 100% cpu load

support files and additional infos already submitted :wink:

Hi, you could try the steps detailed in http://www.jthink.net/jaikozforum/posts/list/6741.page and see if that makes any difference.

It seems to work for some people, but I’m unclear as to whther it really works and if so, why.

Ok, I am attempting to run in Compatibility mode. The first thing I immediately noticed is the log file is generating a bunch of errors as I am I trying to due the MusicBrainz match.

I have attached a sxreen shot of the example. I will watch to see if the CPU utilization climbs. I am wondering it hits a stack issue with the amount of errors. About 20k songs and I would say about 70% are erroring with the error.

Ok, although the error rate was high 15,200 errored out of 20,544. It did finish without any CPU utlitzation issue. Going to try a normal Auto Correct but my guess is that fixed the problem.

Ok, more followup. I tried the Autocorrect and it did cause a CPU utilization issue. Also note that when the CPU starts climbing the status window (error log) slows down to a crawl.

Going to try pinpoint the exact function that is slowing it down.

after a little search on the world wide web i came across a recommendation for jrockit jvm, which may speed up the task
no long after it was installed and i ran the “Auto Tag from MB” task again. there was a major improvement in performance, whether caused by the jaikoz db or not i cant tell. anyway, the cpu usage raised to 100% less often (however unnecessary for shure), but jaikoz seemed to work much faster now despite the 100% nuisance

i cancelled the task again to try it with compatibility mode enabled (WinXP SP3). there’s no improvment. jaikoz or java keeps overloading the cpu

edit: i dont get any errors due to compatibility mode

Attempted Update Metadata from Discogs and started to see the problem at stage 6.

update: managed to autotag my collection. after 19h ~90% were matched successfully :slight_smile:
during step 1 to 4 (check release groupings) the cpu load was at 100% most of the time, during step 5 (check remaining tracks) however, there was no significant cpu load any more

so the issue must be somewhere near release group matching. independet of MB querys (the jaikoz db had had a lot of querys saved from previous trys and the issue was the same), but thats just a guess

edit: cpu time = 56:35:30 (4 cores) =~ 14h 9min

But if you have four cores can’t cpu time go upto 400% ?

like the ordinary task manager, cpu load is displayed as 0-100% in process explorer nt (from sysinternals). cpu time on the other hand is 4times the actual time. so if one core has 100% then the system has 25% load and cpu time is increased 1sec per real second :wink:

sry for the inconvenience. another detail: there were a lot of threads for the process, but only 4 took up most of the cpu cycles (almost 25% each)

Mine is still repeatable every time. Let me know what you want to test next.

What would be useful is if you could get a stack trace of the system when it slows down so we can see what is happening

http://docs.oracle.com/javase/6/docs/technotes/tools/share/jstack.html