Community
Participate
Working Groups
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
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)
Maybe it is enough to change the pattern in the messages property file, so that a ChoiceFormat instance is chosen instead of NumberFormat?
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
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
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
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!