jenkinsci/testng-plugin-plugin — pull request #16 by jglick (2014-08-25 14:28:20+00:00)
Title: Make sure TestNGTestResultBuildAction caches counts and loads results lazily

Currently detailed TestNG results are loaded eagerly as soon as a build record is loaded, even if no request for information about test results was made. For example, one thread can be locking the `RunMap` doing work like this:

```
"Handling POST /computer/…/timeline/data/ : …" …
java.lang.Thread.State: RUNNABLE
at java.io.FileInputStream.available(Native Method)
at java.io.BufferedInputStream.available(Unknown Source)
- locked <…> (a java.io.BufferedInputStream)
at sun.nio.cs.StreamDecoder.inReady(Unknown Source)
at sun.nio.cs.StreamDecoder.implRead(Unknown Source)
at sun.nio.cs.StreamDecoder.read(Unknown Source)
- locked <…> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(Unknown Source)
at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)
at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)
at org.xmlpull.mxp1.MXParser.parseEndTag(MXParser.java:1671)
at org.xmlpull.mxp1.MXParser.nextImpl(MXParser.java:1172)
at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)
at hudson.plugins.testng.parser.ResultsParser.parse(ResultsParser.java:154)
at hudson.plugins.testng.TestNGTestResultBuildAction.loadResults(TestNGTestResultBuildAction.java:97)
at hudson.plugins.testng.TestNGTestResultBuildAction.getResult(TestNGTestResultBuildAction.java:68)
at hudson.plugins.testng.BuildActionConverter.unmarshal(BuildActionConverter.java:68)
at …
at hudson.XmlFile.unmarshal(XmlFile.java:163)
at hudson.model.Run.reload(Run.java:326)
at hudson.model.Run.(Run.java:314)
at hudson.model.AbstractBuild.(AbstractBuild.java:185)
at hudson.maven.AbstractMavenBuild.(AbstractMavenBuild.java:54)
at hudson.maven.MavenModuleSetBuild.(MavenModuleSetBuild.java:146)
at sun.reflect.GeneratedConstructorAccessor89.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at hudson.model.AbstractProject.loadBuild(AbstractProject.java:1154)
at hudson.model.AbstractProject$1.create(AbstractProject.java:344)
at hudson.model.AbstractProject$1.create(AbstractProject.java:342)
at hudson.model.RunMap.retrieve(RunMap.java:222)
at hudson.model.RunMap.retrieve(RunMap.java:59)
at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:688)
- eliminated <…> (a hudson.model.RunMap)
at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:650)
- locked <…> (a hudson.model.RunMap)
at jenkins.model.lazy.AbstractLazyLoadRunMap.search(AbstractLazyLoadRunMap.java:382)
at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:70)
at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:59)
at java.util.AbstractMap$2$1.next(Unknown Source)
at …
at hudson.model.BuildTimelineWidget.doData(BuildTimelineWidget.java:63)
```

while many others sit and wait:

```
"Handling POST /computer/…/timeline/data/ : …" … waiting for monitor entry …
java.lang.Thread.State: BLOCKED (on object monitor)
at jenkins.model.lazy.AbstractLazyLoadRunMap.load(AbstractLazyLoadRunMap.java:649)
- waiting to lock <…> (a hudson.model.RunMap)
at jenkins.model.lazy.AbstractLazyLoadRunMap.search(AbstractLazyLoadRunMap.java:382)
at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:70)
at jenkins.model.lazy.LazyLoadRunMapEntrySet$1.next(LazyLoadRunMapEntrySet.java:59)
at java.util.AbstractMap$2$1.next(Unknown Source)
at …
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138)
at hudson.model.BuildTimelineWidget.doData(BuildTimelineWidget.java:63)
```

There is no reason for the convertor to eagerly load test results here. Load them if and when required.

In practice the pass/fail/skip counts are often needed soon afterwards. For example, displaying the test result graph (if not cached at the HTTP layer) needs this information. And displaying certain kinds of build summaries asks for `Run.getBuildStatusSummary`, which needs these counts, though not any further details. So it makes sense to cache counts in the persisted action, so that test result details need not be loaded from hundreds of historical builds just to show overall graphs and charts. (The current code “caches” them only during a Jenkins session.) To optimize historical records it is necessary to resave `build.xml` if the counts are being computed for the first time.

Saving caches would also require changing the custom convertor. But it is simpler to just use a more modern version of Jenkins core which lets test result actions be a `RunAction2`, for which the `owner` is set externally, so default XStream serialization can be used. (Tricky to confirm, since there are no `@LocalData` tests for loading build records from pre-1.0 versions of the plugin.)

Could fix problems such as [JENKINS-20556](https://issues.jenkins-ci.org/browse/JENKINS-20556). The thread dump in that case does not actually show `TestNGTestResultBuildAction.loadResults` but the thread holding the lock might be mostly doing that and the thread dump just happened to be taken at a moment when it was doing something else.