Bug 372679 - /ajaxEcexutors causes lock congestion in java.util.Currency
Summary: /ajaxEcexutors causes lock congestion in java.util.Currency
Status: ASSIGNED
Alias: None
Product: Hudson
Classification: Technology
Component: Core (show other bugs)
Version: unspecified   Edit
Hardware: All All
: P3 critical (vote)
Target Milestone: ---   Edit
Assignee: Winston Prakash CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-02-27 15:05 EST by Henrik Lynggaard Hansen CLA
Modified: 2012-03-01 04:32 EST (History)
1 user (show)

See Also:


Attachments
Full threaddump taken using kill -3 (278.17 KB, text/plain)
2012-02-29 13:24 EST, Henrik Lynggaard Hansen CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Henrik Lynggaard Hansen CLA 2012-02-27 15:05:39 EST
I have done some thread dumps on a busy hudson, and it appears that the ajax call for the executors causes a lock congestion in java.util.Currency when formatting the timespan string.

I get multiple threads blocked like this:
"Handling POST /ajaxExecutors : RequestHandlerThread[#77]" daemon prio=10 tid=0x00002aab65530800 nid=0x44c1 waiting for monitor entry [0x0000000044c35000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.util.Currency.getInstance(Currency.java:174)
	- waiting to lock <0x00002aaabf1afd48> (a java.util.HashMap)
	at java.util.Currency.getInstance(Currency.java:256)
	at java.text.DecimalFormatSymbols.initialize(DecimalFormatSymbols.java:542)
	at java.text.DecimalFormatSymbols.<init>(DecimalFormatSymbols.java:77)
	at java.text.DecimalFormatSymbols.getInstance(DecimalFormatSymbols.java:140)
	at java.text.NumberFormat.getInstance(NumberFormat.java:750)
	at java.text.NumberFormat.getInstance(NumberFormat.java:376)
	at java.text.MessageFormat.subformat(MessageFormat.java:1237)
	at java.text.MessageFormat.format(MessageFormat.java:836)
	at java.text.Format.format(Format.java:140)
	at java.text.MessageFormat.format(MessageFormat.java:812)
	at org.jvnet.localizer.ResourceBundleHolder.format(ResourceBundleHolder.java:139)
	at hudson.Messages.Util_minute(Messages.java:245)
	at hudson.Util.getTimeSpanString(Util.java:614)
	at hudson.Util.getPastTimeString(Util.java:651)
	at hudson.model.Executor.getTimestampString(Executor.java:328)

Hudson verison:2.1.2
Comment 1 Henrik Lynggaard Hansen CLA 2012-02-27 15:08:13 EST
I just found the thread holding the object, it appears blocked for other reasons??

"Handling POST /ajaxBuildQueue : RequestHandlerThread[#68]" daemon prio=10 tid=0x00002aab65296800 nid=0x107a waiting for monitor entry [0x0000000043b25000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.util.Currency.getInstance(Currency.java:174)
	- locked <0x00002aaabf1afd48> (a java.util.HashMap)
	at java.util.Currency.getInstance(Currency.java:256)
	at java.text.DecimalFormatSymbols.initialize(DecimalFormatSymbols.java:542)
	at java.text.DecimalFormatSymbols.<init>(DecimalFormatSymbols.java:77)
	at java.text.DecimalFormatSymbols.getInstance(DecimalFormatSymbols.java:140)
	at java.text.NumberFormat.getInstance(NumberFormat.java:750)
	at java.text.NumberFormat.getInstance(NumberFormat.java:376)
	at java.text.MessageFormat.subformat(MessageFormat.java:1237)
	at java.text.MessageFormat.format(MessageFormat.java:836)
	at java.text.Format.format(Format.java:140)
	at java.text.MessageFormat.format(MessageFormat.java:812)
	at org.jvnet.localizer.ResourceBundleHolder.format(ResourceBundleHolder.java:139)
	at hudson.model.Messages.AbstractProject_BuildInProgress(Messages.java:1317)
	at hudson.model.AbstractProject$BecauseOfBuildInProgress.getShortDescription(AbstractProject.java:1061)
	at hudson.model.Queue$Item.getWhy(Queue.java:1230)
Comment 2 Henrik Lynggaard Hansen CLA 2012-02-27 16:35:35 EST
Maybe it is enough to change the pattern in the messages property file, so that a ChoiceFormat instance is chosen instead of NumberFormat?
Comment 3 Winston Prakash CLA 2012-02-27 17:08:05 EST
Henrik, Could you run jstack <pid> and attach the full stacktrace. Also you can attach jconsole to the <pid> and see if it reports any deddalock
Comment 4 Henrik Lynggaard Hansen CLA 2012-02-29 13:24:38 EST
Created attachment 211826 [details]
Full threaddump taken using kill -3

This is a full thread dump taken using kill -3. It doesn't report any deadlocks
Comment 5 Henrik Lynggaard Hansen CLA 2012-02-29 13:26:22 EST
I din't do any jconsole stuff, as the VM was already restarted. 

In order to follow hudson performance we plan to set up a cron job to do kill -3 on a regular basis such as every 15 minutes
Comment 6 Steve Christou CLA 2012-03-01 04:32:36 EST
I think I found your deadlock. Look at hudson-core\src\main\java\hudson\util\OneShotEvent.java on line 79.

Any call made to Object.wait() MUST be in a loop!