Monday, November 12, 2012

Running Dojo DOH tests headlessly with PhantomJS...

One of the challenges was to run our tests in the continuous integration environment. This would enable emailing developers if a check-in caused tests to fail. Our service tests are written using Junit/HttpClient and this was a relatively easy task to complete. But our UI tests are written in Dojo's DOH and the same task posed a little more of a challenge.

We looked at PhantomJS, Zombie.js and HTMLUnit to see which one would solve our problem and we could quickly adopt. We found that PhantomJS seemed to work the best when using the DOH Runner. Zombie.js couldn't seem to load the DOH Runner correctly and HTMLUnit worked for some simple tests, but gave numerous errors while running.

PhantomJS Script
The PhantomJS script to initiate the DOH Runner turned out to be straight-forward using the the Quick Start and Reference API documentation.

phantomDohRunner.js
    var page = require('webpage').create(),
    url, text;

    if (!require('system').isSSLSupported) {
        console.log('Need SSL');
        phantom.exit();
    } else {
        console.log('Have SSL');
    }
       
    // set support for cookies
    phantom.cookiesEnabled = true;
    var debugx=false;
    
    page.onConsoleMessage = function (msg) {
        console.log(msg);
    };
    
    page.onError = function(msg, trace) {
        console.log("Error Encountered: " + msg);
    };
    
    page.onInitialized = function() {
        page.evaluate(function() {
            document.addEventListener("DOMContentLoaded", function() {
                console.log("DOM content has loaded.");
            }, false);
        });
    };
    
    page.onResourceRequested = function(request) {
        if (debugx) console.log("Request (#" + request.id + "): " + JSON.stringify(request));
    };
    
    page.onResourceReceived = function(response) {
        if (debugx) console.log('Response (#' + response.id + ', stage "' + response.stage + '"): ' + JSON.stringify(response));
    };
    

    // must have URL to hit
    url = phantom.args[0];
    if (typeof url === "undefined") {
        console.log("Error: arg[0] must be a fully qualified URL.\nCommand format is: 'phantomjs phantomDohRunner.js \"URL\" [timeout in millis]'."); 
        console.log("For Example:\nphantomjs phantomDohRunner.js \"http://HOST/tester/dojo/util/doh/runner.html?test=dojo/tests/_base/array\" 20000\n\n");        
        // phantom.exit doesn't terminate the program, so put in conditional
        phantom.exit();
    } else {
    
        // get timeout from command line or default
        timeout = phantom.args[1];
        if (typeof timeout === "undefined") {
            timeout = 60000; // default to 1 minute
        }
        
        console.log("URL = " + url);
        console.log("Timeout = " + timeout + " milliseconds\n\n");
        
        page.open(url, function () {
    
            setTimeout(function(){
                    page.render("phantomDohRunnerFinish.png");
                    console.log("Closing down.");
                    phantom.exit();
            }, timeout);
    
        });
    }

The PhantomJS script above takes a URL of the DOH Runner and the time to wait for the tests to complete (in milliseconds).

For example: phantomjs phantomDohRunner.js "http://HOST/tester/dojo/util/doh/runner.html?test=dojo/tests/_base/array" 20000

Note: Currently, for some sites PhantomJS doesn't work well when using a secure protocol (https). We asked the PhantomJS forum and found this is a known issue and a fix has been proposed. For now the workaround is to use a client-side proxy (e.g. Fiddler) that can manage the SSL handshake and allows PhantomJS interactions. 

 The script above also renders a phantomDohRunnerFinish.png image after the timer expires.  It should look something like:



Get the log to the console
I know what you are asking, "why don't I see the log output in the console?".  The answer is that the DOH Runner redirects the output, so it doesn't display.

Now we need to get access to the output displayed in the Runner.  Since we wanted it to be able to execute the Runner correctly in the browser, we decided to resend the output to the console if it was run by a Phantom agent.

We made the following changes to the DOH js files to make this happen (diff'ed output below):

util/doh/_parseURLargs.js (keep original console ref when run from DOH Runner)
1,4d0
< // need to keep original window console to log for headless runners like phantomjs (called from runner.html)
< if(typeof window.console !== "undefined" && typeof window.consoleOrig === 'undefined') {
<     window.consoleOrig=window.console;
< }

util/doh/runner.js (keep original console ref when run directly though doh/main)
1523,1526c1523
<       // Phantomjs - set to fix summary printing timing issue when running headlessly.
<       setTimeout(function() {
<           this._report();
<     }.bind(this), 500);
---
>       this._report();
1537,1540d1533
< // need to keep original window console to log for headless runners like phantomjs (called from runner.html & doh/main)
< if(typeof window!="undefined" && typeof window.console !== "undefined" && typeof window.consoleOrig === 'undefined') {
<     window.consoleOrig = window.console;
< }

util/doh/_browserRunner.js (if PhantomJS agent, send output to orig console too)
1,9c1
< define("doh/_browserRunner", ["dojo/main", "doh/runner", "dojo/_firebug/firebug"], function(dojo, doh) {
<
<     // check to see if we need to log to orignal console for phantomjs and so we don't double log if running in a true browser
<     var phantomRunner=false;
<     if(navigator.userAgent.toLowerCase().indexOf("phantomjs") > 0) {
<         window.consoleOrig.log("*** Found PhantomJS UserAgent ***");
<         phantomRunner=true;
<     }
<
---
> define(["dojo/main", "doh/runner", "dojo/_firebug/firebug"], function(dojo, doh) {
393,419c385,407
<         }else if(window["console"]){
<             if(console.error){
<                 doh.error = function(){
<                     sendToLogPane.call(window, arguments);
<                     console.error(Array.prototype.join.call(arguments, " "))
<                     if(phantomRunner) window.consoleOrig.log(Array.prototype.join.call(arguments, " "));
<                 };
<             }
<             if(console.debug){
<                 doh.debug = function(){
<                     sendToLogPane.call(window, arguments);
<                     console.debug(Array.prototype.join.call(arguments, " "))
<                     if(phantomRunner) window.consoleOrig.log(Array.prototype.join.call(arguments, " "));
<                 };
<             }else if(console.info){
<                 doh.debug = function(){
<                     sendToLogPane.call(window, arguments);
<                     console.info(Array.prototype.join.call(arguments, " "))
<                     if(phantomRunner) window.consoleOrig.log(Array.prototype.join.call(arguments, " "));
<                 };
<             }else{
<                 doh.debug = function(){
<                     sendToLogPane.call(window, arguments);
<                     console.log("DEBUG:"+ Array.prototype.join.call(arguments, " "));
<                     if(phantomRunner) window.consoleOrig.log("DEBUG:"+ Array.prototype.join.call(arguments, " "));
<                 };
<             }
---
>               }else if(window["console"]){
>                       if(console.error){
>                               doh.error = function(){
>                                       sendToLogPane.call(window, arguments);
>                                       console.error(Array.prototype.join.call(arguments, " "))
>                               };
>                       }
>                       if(console.debug){
>                               doh.debug = function(){
>                                       sendToLogPane.call(window, arguments);
>                                       console.debug(Array.prototype.join.call(arguments, " "))
>                               };
>                       }else if(console.info){
>                               doh.debug = function(){
>                                       sendToLogPane.call(window, arguments);
>                                       console.info(Array.prototype.join.call(arguments, " "))
>                               };
>                       }else{
>                               doh.debug = function(){
>                                       sendToLogPane.call(window, arguments);
>                                       console.log("DEBUG:"+ Array.prototype.join.call(arguments, " "));
>                               };
>                       }

Now when you re-run the command above, you should see the following output in your console and the finished image of the page will render correctly as well.

c:\dev\ui\test>phantomjs phantomDohRunner.js "http://hostserver/tester/dojo/util/doh/runner.html?test=dojo/tests/_base/array" 20000
WE HAVE SSL
URL = http://hostserver/tester/dojo/util/doh/runner.html?test=dojo/tests/_base/array
Timeout = 20000 milliseconds

DOM content has loaded.
14 tests to run in 1 groups
------------------------------------------------------------
GROUP "tests._base.array" has 14 tests to run
PASSED test: testIndexOf 1 ms
PASSED test: testIndexOfFromIndex 1 ms
PASSED test: testLastIndexOf 0 ms
PASSED test: testLastIndexOfFromIndex 0 ms
PASSED test: testForEach 0 ms
PASSED test: testForEach_str 0 ms
PASSED test: testForEach_string_callback 2 ms
PASSED test: testEvery 2 ms
PASSED test: testEvery_str 0 ms
PASSED test: testSome 1 ms
PASSED test: testSome_str 1 ms
PASSED test: testFilter 1 ms
PASSED test: testFilter_str 0 ms
PASSED test: testMap 0 ms
WOOHOO!!
------------------------------------------------------------
| TEST SUMMARY:
------------------------------------------------------------
         14 tests in 1 groups
         0 errors
         0 failures


After we took this approach, we attended a presentation given by Dylan Schiemann and he mentioned that we could have solved for logging by using Dojo Analytics.  Currently the solution above is working for us and will use it for now.

Hope this helps - Thanks - Mark :-)

2 comments:

  1. As an addition, when I ran this on my Jenkins server although there were errors/failures it always passed due to the phantom.exit(); effectively returning an error level of 0.

    I've modified the code to change the error level if any errors/failures:

    In runner.js:

    doh._report = function(){
    // summary:
    // a private method to be implemented/replaced by the "locally
    // appropriate" test runner

    // this.debug("ERROR:");
    // this.debug("\tNO REPORTING OUTPUT AVAILABLE.");
    // this.debug("\tIMPLEMENT doh._report() IN YOUR TEST RUNNER");

    this.debug(this._line);
    this.debug("| TEST SUMMARY:");
    this.debug(this._line);
    this.debug("\t", this._testCount, "tests in", this._groupCount, "groups");
    this.debug("\t", this._errorCount, "errors");
    this.debug("\t", this._failureCount, "failures");

    // Throw an error if there any any errors/failures
    if (this._errorCount > 0) {
    throw new Error(this._errorCount + " test errors found");
    }
    if (this._failureCount > 0) {
    throw new Error(this._failureCount + " test failures found");
    }
    };

    phantomDohRunner.js:

    page.onError = function(msg, trace) {
    console.log("Error Encountered: " + msg);
    phantom.exit(1);
    };

    ReplyDelete
  2. You don't need to modify the runner at all. Just use setInterval to regularly run a function which checks to see if doh has finished by enquiring on the value of the log output DOM element, and using some simple regexes to test it:

    This also means you don't need to guess how long your test suite takes. It will exit

    setInterval(function() {
    var log = page.evaluate(function() {
    return document.getElementById("logBody").innerHTML;
    }),
    errors,
    failures;
    if (/TEST SUMMARY/.test(log)) {
    console.log("Tests have finished");
    errors = new Number(/(\d+) errors/.exec(log)[1]);
    failures = new Number(/(\d+) failures/.exec(log)[1]);
    if (errors) {
    console.log(errors + " errors");
    }
    if (failures) {
    console.log(failures + " failures");
    }
    if (errors || failures) {
    console.log(log);
    phantom.exit(1);
    }
    phantom.exit();
    }
    }, 500);

    ReplyDelete