Non instrumented sources still affect execution time.

[simoami]

For a long time I've been wondering why Saga takes so long to instrument a single file (150 LoC).

I was then able to confirm that the inclusion of other files and libraries does affect the overall execution time even if these other files are excluded with noInstrumentPatterns.

A practical example is to include the ExtJS library as a fake dependency and observe how instrumentation of the single file changes from seconds to minutes, even with exclusion rules for those extra files.

[timurstrekalov]

Please, post your configuration and, if possible, your directory/file layout.

[simoami]

Here's a sample project based on the jasmine /saga coverage demo: download

I added to it 2 ExtJs framework files and referenced them in the jasmine config as. These files are not really used by the test subject. Just wanted to show the side effects of including them:

<sourceIncludes>
    <!-- Framework files -->
    <include>**/ext-3.4.1/adapter/ext/ext-base.js</include>
    <include>**/ext-3.4.1/ext-all-debug.js</include>
    <!-- Tested Components -->
    <include>**/element_mover.js</include>
</sourceIncludes>

Under Saga, I set the config to exclude the framework files:

<configuration>
    <baseDir>http://localhost:${jasmine.serverPort}</baseDir>
    <outputDir>${project.build.directory}/coverage</outputDir>
    <noInstrumentPatterns>
        <pattern>.*/ext.*</pattern> <!-- Don't instrument the framework -->
        <pattern>.*/spec/.*</pattern> <!-- Don't instrument specs -->
    </noInstrumentPatterns>
    <excludes>**/ext-3.4.1/**,ext*.js</excludes>
</configuration>

Then ran mvn verify. It looked like it froze but eventually completed in 5 minutes for what typically takes a few seconds:

[INFO] Setting FIREFOX_17 as browser version
[INFO] Setting HTML, RAW, COBERTURA as report formats
[WARNING] Including and excluding tests by patterns only makes sense in the context of tests run off the filesystem, ignoring
[INFO] 1 tests found
[INFO] Using up to 1 threads
[INFO] Output strategy set to TOTAL
[INFO] Using the following no-instrument patterns:
    .+__from_\d+_\d+_to_\d+_\d+$
    .*/spec/.*
    .+#\d+\(eval\)\(\d+\)
    .+JavaScriptStringJob
    .*/ext.*
    injected script
[INFO] Running test at http://localhost:51630
[INFO] Quitting browser
[INFO] Test run finished
[INFO] Writing HTML coverage report: /Users/username/Downloads/saga-with-jasmine-sample-with-extjs/target/coverage/total-report.html
[INFO] Writing RAW coverage report: /Users/username/Downloads/saga-with-jasmine-sample-with-extjs/target/coverage/total-coverage.dat
[INFO] Writing COBERTURA coverage report: /Users/username/Downloads/saga-with-jasmine-sample-with-extjs/target/coverage/total-coverage.xml
...
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 5:14.714s
[INFO] Finished at: Sun Dec 22 16:32:22 EST 2013
[INFO] Final Memory: 27M/638M
[INFO] ------------------------------------------------------------------------

[timurstrekalov]

Ah. Sadly, this is a side effect of including any JavaScript files into your tests.

Since you are including ExtJS sources into your tests, they are being properly executed by the JS engine (even though, based on your no-instrument patterns they are not going to be instrumented, and they are not) once the HTML files are loaded.

However, there is a setting for the JS engine that controls the timeout for background JavaScript jobs (e.g. setTimeout, setInterval), which is controlled by the backgroundJavaScriptTimeout configuration property for Saga (set by default to 5 minutes – which is exactly what affects your build). Apparently, when you load ExtJS files, they spawn background jobs that are never removed, so the JS engine's setting kicks in and it waits for them to finish execution or, in our case, time out.

So, the problem lies within ExtJS itself + the fact that you are including them into your test runners (in jasmine), and, well, the default timeout setting for Saga :) normally I'd advise fixing the original problem (there should be no background jobs running forever), but, since it's kinda out of your hands, you can just tweak the setting to put any timeout you see as reasonable – however, note that this may affect your other tests, since you may rely on background jobs in your tests somehow.

I hope this makes sense :)

[simoami]

Thanks for the explanations but I dont think I get the whole picture.

Considering the fact that loading of the framework files into memory takes a second or less in a normal browser and that there's no explicit call to the framework in the attached poc, can you shed some light on what's really causing execution time to stall? For example the Jasmine plugin runs all my tests in 5 seconds. these tests use ExtJS as dependency. So I'm wondering why ExtJS is the problem.

[timurstrekalov]

Sure. Imagine a JS file that contains something like this:

setInterval(function () {}, 5000);

When Saga runs, it waits for the page to load and then waits for all JavaScript jobs to be executed, with a default timeout of 5 minutes. Given that the aforementioned interval will never be cleared, this will run forever. It takes as little as loading the file (i.e. by including it into your SpecRunner via Jasmine) for it to be executed by the JS engine.

Now, I cannot prove it, since I don't exactly fancy going through ExtJS code in order to find the background job that's causing the issue, but I have a feeling that I might be right here.

Regarding Jasmine, I'm afraid it works a bit differently. Jasmine is the testing framework that executes the tests, so it just waits for a certain flag to be raised (a JS variable, something like "finished" to be set to true, I think), while Saga has to rely on a generic way of dealing with such issues (by simply waiting until all scripts are executed or timing out). Naturally, Saga could support Jasmine natively so that it could use the same variable to figure out whether the tests have finished, but until now this hasn't been an issue.

In short, Saga does this

• load the test runner
• wait for the page to load
• wait for all background jobs to finish or timeout within backgroundJavaScriptTimeout milliseconds

[simoami]

Aha, you're right!

I looked up the ExtJS source code and found the following command. It's ran unconditionally:

El.collectorThreadId = setInterval(garbageCollect, 30000);

The following command practically solves the problem. I added it as a global spec helper:

clearInterval(Ext.Element.collectorThreadId);

Thanks for your help. Hopefully this serves as a reference for others who use ExtJS and want to use Saga for code coverage.

PS: it would be helpful to add a note for ways to troubleshoot slow running coverage sessions. Example. The presence of setInterval and setTimeout.

[timurstrekalov]

Good point, I've been thinking about this myself, because it's not the first time someone had a problem like that. Well, I guess this has to be done :)

Glad to see it worked out for you :+1: