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 FIREFOX17 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 SelectChannelConnector@0.0.0.0: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.