WARN com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable - Error running test ... null

[worldjoe]

I get blank coverage reports quite often. I took a look at the warning above and dug around a bit. The exception message isn't helpful since it's null. So I modified the source to output a stack trace as well:

[java.util.LinkedList$ListItr.next(LinkedList.java:891)
com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.collectAndWriteRunStats(TestRunCoverageStatisticsCallable.java:90)
com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.runTest(TestRunCoverageStatisticsCallable.java:79)
com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.call(TestRunCoverageStatisticsCallable.java:39)
com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.call(TestRunCoverageStatisticsCallable.java:18)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
java.util.concurrent.FutureTask.run(FutureTask.java:166)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:724)]

The trace tells me that TestRunCoverageStatisticsCallable.collectAndWriteRunStats is failing on line 90. In particular getLocalBrowser().getScriptDataList() is returning a List that is changing/modifiying the underlying list in another thread (or perhaps in the for loop itself).

I haven't been able to debug why it's changing yet. But I put a placeholder fix to solve the problem on my local machine for now.
try {
Thread.sleep(8000);
} catch (Exception e) {}
for (final ScriptData data : getLocalBrowser().getScriptDataList()) {

I just added a sleep before that iterator. So far that seems to work. Which would imply someone else is modifying the list, and not the for loop itself. No way for me to know for sure without more time to debug.

[worldjoe]

Here's my full log (with stack trace output added):

[INFO] --- saga-maven-plugin:1.5.3:coverage (default) @ healthcare ---
11:28:40.607 [main] INFO com.github.timurstrekalov.saga.core.cfg.InstanceFieldPerPropertyConfig - Setting FIREFOX_17 as browser version
11:28:40.621 [main] INFO com.github.timurstrekalov.saga.core.cfg.InstanceFieldPerPropertyConfig - Setting HTML, RAW, COBERTURA as report formats
11:28:40.634 [main] INFO com.github.timurstrekalov.saga.core.DefaultCoverageGenerator - 1 tests found
11:28:40.634 [main] INFO com.github.timurstrekalov.saga.core.DefaultCoverageGenerator - Using up to 1 threads
11:28:40.635 [main] INFO com.github.timurstrekalov.saga.core.DefaultCoverageGenerator - Output strategy set to TOTAL
11:28:40.635 [main] INFO com.github.timurstrekalov.saga.core.DefaultCoverageGenerator - Using the following no-instrument patterns:
.+/dependencies/.+.js
.+/platform.twitter.com/..+.js
.+/stats.g.doubleclick.net/.+.js
.+_from\d+\d+to\d+\d+$
.+/www.google-analytics.com/.+.js
.+#\d+(eval)(\d+)
.+JavaScriptStringJob
.+/connect.facebook.net/..+.js
injected script
11:28:40.657 [pool-1-thread-1] INFO com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable - Running test at http://172.28.165.131:49263
11:28:40.740 [pool-1-thread-1] INFO org.eclipse.jetty.server.Server - jetty-8.1.14.v20131031
11:28:40.770 [pool-1-thread-1] INFO org.eclipse.jetty.server.AbstractConnector - Started [email protected]:49550
11:28:40.770 [pool-1-thread-1] INFO com.github.timurstrekalov.saga.core.server.InstrumentingProxyServer - Proxy server started on port 49550
Apr 15, 2014 11:28:40 AM org.openqa.selenium.phantomjs.PhantomJSDriverService
INFO: executable: /Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/phantomjs-maven-plugin/phantomjs-1.9.2-macosx/bin/phantomjs
Apr 15, 2014 11:28:40 AM org.openqa.selenium.phantomjs.PhantomJSDriverService
INFO: port: 4982
Apr 15, 2014 11:28:40 AM org.openqa.selenium.phantomjs.PhantomJSDriverService
INFO: arguments: [--proxy-type=http, --proxy=localhost:49550, --webdriver=4982, --webdriver-logfile=/Users/jelwell/dev/cfp/depot/healthcare/tthealth/phantomjsdriver.log]
Apr 15, 2014 11:28:40 AM org.openqa.selenium.phantomjs.PhantomJSDriverService
INFO: environment: {}
2014-04-15 11:28:41.692 phantomjs[2963:507] *** WARNING: Method userSpaceScaleFactor in class NSView is deprecated on 10.7 and later. It should not be used in new applications. Use convertRectToBacking: instead.
PhantomJS is launching GhostDriver...
[INFO - 2014-04-15T18:28:41.741Z] GhostDriver - Main - running on port 4982
[INFO - 2014-04-15T18:28:41.972Z] Session [c55a6e10-c4cb-11e3-8a2d-f1c2ed8cebfb] - _decorateNewWindow - page.settings: {"XSSAuditingEnabled":false,"javascriptCanCloseWindows":true,"javascriptCanOpenWindows":true,"javascriptEnabled":true,"loadImages":true,"localToRemoteUrlAccessEnabled":false,"userAgent":"Mozilla/5.0 (Macintosh; Intel Mac OS X) AppleWebKit/534.34 (KHTML, like Gecko) PhantomJS/1.9.2 Safari/534.34","webSecurityEnabled":true}
[INFO - 2014-04-15T18:28:41.972Z] Session [c55a6e10-c4cb-11e3-8a2d-f1c2ed8cebfb] - page.customHeaders: - {}
[INFO - 2014-04-15T18:28:41.972Z] Session [c55a6e10-c4cb-11e3-8a2d-f1c2ed8cebfb] - CONSTRUCTOR - Desired Capabilities: {"javascriptEnabled":true,"proxy":{"socksUsername":null,"noProxy":null,"httpProxy":"localhost:49550","socksPassword":null,"ftpProxy":null,"sslProxy":"localhost:49550","proxyAutoconfigUrl":null,"proxyType":"MANUAL","class":"org.openqa.selenium.Proxy","autodetect":false,"socksProxy":null,"hCode":539481296},"phantomjs.binary.path":"/Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/phantomjs-maven-plugin/phantomjs-1.9.2-macosx/bin/phantomjs"}
[INFO - 2014-04-15T18:28:41.972Z] Session [c55a6e10-c4cb-11e3-8a2d-f1c2ed8cebfb] - CONSTRUCTOR - Negotiated Capabilities: {"browserName":"phantomjs","version":"1.9.2","driverName":"ghostdriver","driverVersion":"1.0.4","platform":"mac-unknown-32bit","javascriptEnabled":true,"takesScreenshot":true,"handlesAlerts":false,"databaseEnabled":false,"locationContextEnabled":false,"applicationCacheEnabled":false,"browserConnectionEnabled":false,"cssSelectorsEnabled":true,"webStorageEnabled":false,"rotatable":false,"acceptSslCerts":false,"nativeEvents":true,"proxy":{"socksUsername":null,"noProxy":null,"httpProxy":"localhost:49550","socksPassword":null,"ftpProxy":null,"sslProxy":"localhost:49550","proxyAutoconfigUrl":null,"proxyType":"MANUAL","class":"org.openqa.selenium.Proxy","autodetect":false,"socksProxy":null,"hCode":539481296}}
[INFO - 2014-04-15T18:28:41.972Z] SessionManagerReqHand - _postNewSessionCommand - New Session Created: c55a6e10-c4cb-11e3-8a2d-f1c2ed8cebfb
[INFO] Skipping spec runner generation, because an identical spec runner already exists.
2014-04-15 11:28:43.125 phantomjs[2963:507] CoreText performance note: Client called CTFontCreateWithName() using name "Times New Roman" and got font with PostScript name "TimesNewRomanPSMT". For best performance, only use PostScript names when calling this API.
2014-04-15 11:28:43.126 phantomjs[2963:507] CoreText performance note: Set a breakpoint on CTFontLogSuboptimalRequest to debug.
11:28:49.567 [pool-1-thread-1] WARN com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable - Error running test http://172.28.165.131:49263: null : [java.util.LinkedList$ListItr.next(LinkedList.java:891), com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.collectAndWriteRunStats(TestRunCoverageStatisticsCallable.java:90), com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.runTest(TestRunCoverageStatisticsCallable.java:79), com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.call(TestRunCoverageStatisticsCallable.java:39), com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable.call(TestRunCoverageStatisticsCallable.java:18), java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334), java.util.concurrent.FutureTask.run(FutureTask.java:166), java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471), java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334), java.util.concurrent.FutureTask.run(FutureTask.java:166), java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145), java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615), java.lang.Thread.run(Thread.java:724)]
11:28:49.567 [pool-1-thread-1] INFO com.github.timurstrekalov.saga.core.TestRunCoverageStatisticsCallable - Quitting browser
[INFO - 2014-04-15T18:28:49.581Z] ShutdownReqHand - _handle - About to shutdown
11:28:50.083 [main] INFO com.github.timurstrekalov.saga.core.DefaultCoverageGenerator - Test run finished
11:28:50.099 [main] INFO com.github.timurstrekalov.saga.core.reporter.RawReporter - Writing RAW coverage report: /Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/coverage/total-coverage.dat
11:28:50.164 [main] INFO com.github.timurstrekalov.saga.core.reporter.CoberturaReporter - Writing COBERTURA coverage report: /Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/coverage/total-coverage.xml
11:28:50.173 [main] INFO com.github.timurstrekalov.saga.core.reporter.HtmlReporter - Writing HTML coverage report: /Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/coverage/total-report.html
[INFO]
[INFO] --- maven-install-plugin:2.3.1:install (default-install) @ healthcare ---
[INFO] Installing /Users/jelwell/dev/cfp/depot/healthcare/tthealth/pom.xml to /Users/jelwell/.m2/repository/com/intuit/turbotax/healthcare/1.0.15-SNAPSHOT/healthcare-1.0.15-SNAPSHOT.pom
[INFO] Installing /Users/jelwell/dev/cfp/depot/healthcare/tthealth/target/healthcare-1.0.15-SNAPSHOT.zip to /Users/jelwell/.m2/repository/com/intuit/turbotax/healthcare/1.0.15-SNAPSHOT/healthcare-1.0.15-SNAPSHOT.zip
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 32.345s
[INFO] Finished at: Tue Apr 15 11:28:50 PDT 2014
[INFO] Final Memory: 27M/66M
[INFO] ------------------------------------------------------------------------

[worldjoe]

I have to wonder if some of my code is the culprit making the list change size. In particular I have code like this:
(function(d, s, id) {
var js, fjs = d.getElementsByTagName(s)[0];
js = d.createElement(s); js.id = id;
js.src = "//connect.facebook.net/en_US/all.js#xfbml=1&appId=98918901269";
fjs.parentNode.insertBefore(js, fjs);
}(document, 'script', 'facebook-jssdk'));
}

     //Twitter
    window.twttr = (function (d,s,id) {
      var t, tjs, tfjs = d.getElementsByTagName(s)[0];
      tjs=d.createElement(s); tjs.id=id;
      tjs.src="//platform.twitter.com/widgets.js"; 
      tfjs.parentNode.insertBefore(tjs, tfjs);
      return window.twttr || (t = { _e: [], ready: function(f){ t._e.push(f); } });
    }(document, "script", "twitter-wjs"));

Note that it injects a script into the dom. My coverage reports seem to be printed out correctly more often if I comment out all that code.