Protractor triggers selenium exception, exits immediately saying all tests passed

[samends]

When I run protractor, selenium opens chrome browser window then immediately closes. It causes selenium to show the following exception backtrace.

13:39:42.306 WARN - Exception thrown
org.openqa.selenium.remote.SessionNotFoundException: Session ID is null. Using WebDriver after calling quit()?
Build info: version: '2.48.2', revision: '41bccdd', time: '2015-10-09 19:59:12'
System info: host: 'WLDMB0118.local', ip: '10.70.229.141', os.name: 'Mac OS X', os.arch: 'x86_64', os.version: '10.10.5', java.version: '1.7.0_79'
Driver info: driver.version: RemoteWebDriver
    at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:134)
    at org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:82)
    at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:620)
    at org.openqa.selenium.remote.RemoteWebDriver$RemoteWebDriverOptions$RemoteWindow.setSize(RemoteWebDriver.java:853)
    at org.openqa.selenium.support.events.EventFiringWebDriver$EventFiringWindow.setSize(EventFiringWebDriver.java:621)
    at org.openqa.selenium.remote.server.handler.SetWindowSize.call(SetWindowSize.java:53)
    at org.openqa.selenium.remote.server.handler.SetWindowSize.call(SetWindowSize.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at org.openqa.selenium.remote.server.DefaultSession$1.run(DefaultSession.java:176)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

Protractor immediately exits while showing every test passed. By this I mean that all output from the spec reporter is green. The entire process takes approximate 1.78 seconds. We have tested this same suite with the exact same versions on 2 additional macs and one windows machine with the test suite behaving as expected. We can see the browser step through the protractor tests normally. On these other computers the process takes about 40 seconds.

We have tried multiple things to fix the problem including blowing away protractor, node modules, and reinstalling everything. Try as we might we can not reproduce this problem elsewhere. However protractor is clearly exhibiting the incorrect behavior, because if the selenium error occurs and the test cannot be carried out then protractor should not signal all tests as passing.

I am writing this both to report a bug and to ask for any help that can be offered in fixing this issue.

Please find information about my environment below:

Mac OSX 10.10.5

Darwin hostname.local 14.5.0 Darwin Kernel Version 14.5.0: Wed Jul 29 02:26:53 PDT 2015; root:xnu-2782.40.9~1/RELEASE_X86_64 x86_64

Google Chrome 47.0.2526.106 (Official Build) (64-bit)

Protractor version: 3.0.0.

Node version: 5.2.0

Grunt version: grunt-cli v0.1.13
grunt v0.4.5

Thanks very much for any help you can offer and please let me know if I can provide more information to help solve or diagnosis this problem.

[sjelin]

Can you show your config file?

[samends]

Sure, here it is:

var e2eParentFolder = '../test/e2e';

exports.config = {

  specs: [e2eParentFolder+'/**/*.spec.js'],

  suites: {
  // ...snip...
  },

  multiCapabilities: [{
   browserName: 'chrome',
   maxInstances: 1
  }],

  allScriptsTimeout: 11000,
  getPageTimeout: 10000,

  framework: 'jasmine2',

  jasmineNodeOpts: {
   isVerbose: false,
   showColors: true,
   includeStackTrace: false,
   defaultTimeoutInterval: 40000,
   print: function() {}
  },

  onPrepare: function () {

    var SpecReporter = require('jasmine-spec-reporter');
    var jasmineReporters = require('jasmine-reporters');

    jasmine.getEnv().addReporter(new SpecReporter({displayStacktrace: 'all'}));

    jasmine.getEnv().addReporter(
      new jasmineReporters.JUnitXmlReporter({
        consolidateAll: true,
        savePath: 'output',
        filePrefix: 'xmloutput'
      })
    );

    (function login() {
      var disableLogin = browser.params.disableLogin, password;
      var width = 1024, height = 1024;

      var loginUrl = browser.params.loginUrl || browser.baseUrl;

      browser.driver.manage().window().setSize(width, height);

      browser.driver.get(loginUrl);

      if (disableLogin !== true) {

        password = process.env.PASSWORD;

        if (typeof password !== 'undefined') {

          browser.driver.findElement(by.id('username')).sendKeys('username');
          browser.driver.findElement(by.id('passwordinput')).sendKeys(password);
          browser.driver.findElement(by.css('button.btn')).click();

          return browser.driver.wait(function() {
            return browser.driver.get(browser.baseUrl).then(function(url) {
              return true;
            });
          }, 10000);

        } else {
          throw new Error('PASSWORD was not provided.');
        }

      } 
    }());

  }
}

[yonkeltron]

This problem seems like it has two parts. For the first, it seems like there's a Selenium issue. Second, if there is such a Selenium issue, Protractor should never report all green.

[vstene]

I received the same error on my suite updating from 2.5.1 after all tests passed. Rolled back instead of investigating more.

[JosephBittman]

I am having the same issue. I have cornered the issue down to browser.wait no longer working as before. When it times out, it does not throw any catchable error, instead everything quits with no output. This is my browser.wait that executes soon after the first page loads:

this.waitForPresent = function(elem, timeout) {
    timeout = (timeout === undefined) ? 30000 : timeout;
    return browser.wait(function() {
      console.log('waiting');
      return elem.isPresent().then(function(value){
        return value;
      });
    }, timeout);
  };

This is the test output I get:

waiting
waiting
waiting
waiting
waiting
waiting
....
waiting

And that's it. No process exits message; no further output. Just put back on the command line ready for another command to be ran.

Calling code does:
waitForPresent(...).then(function(){}, function(){}); and catches any timeouts and then knows how to proceed testing in this case. However, it no longer catches any errors. I believe the error-handling is broken and it is bubbling all the way up the chain with no exception handlers properly catching the errors and therefore no console output ever occurs either.

[juliemr]

I'm unable to reproduce this issue. Everything I try results in Protractor exiting with code 1. Here's an example of using wait that times out:

 // in config:
  onPrepare: function() {
    browser.wait(function() {
      console.log('waiting...');
      return false;
    }, 1000);
  }

This results in Error: Wait timed out after 1000ms and an exit code of 1.

I'm going to close this issue as unable to reproduce. However, if you are able to create a reproducible case we can run, please open up a new issue! Thanks.

[vstene]

Seems like the issue for me was with calling browser in a global afterEach.
Made a repo to reproduce: https://github.com/vstene/protractor-session-id-null

I only see the error on Browserstack / Sauce Labs.

[EricHeath-AI]

We also had benchpress 2.0.0-beta.6 in our package.json.
benchpress depends on selenium-webdriver 2.52.0.
protractor 3.1.1 wants 2.48.2.

This setup forced npm to create:

myapp/node_modules/protractor/node_modules/selenium_webdriver -> 2.48.2 (for protractor)
myapp/node_modules/selenium_webdriver -> 2.52.0 (for benchpress)

And from what I can see, protractor is then resolving selenium-webdriver 2.52.0 and not working correctly. (I guess jasminewd2 searches up from myapp/node_modules/jasminewd2 and finds myapp/node_modules/selenium_webdriver?)

It was crazy to see all the steps queued up in the webdriver control flow (getSchedule()), but then to have the test complete instantly... sort of hard to trace this one back to a root cause.

I can help to create a simple project with the problem if it helps. This is my best lead so far on this one though.

I should add: we run a couple of envs, but:
os: mac 10.10.5 or ubuntu 12.04/14.04/15.10
node: 4.2.4 via brew / n
jdk: 1.7.0_79
protractor: 3.1.1 (selenium-standalone 2.51.0, chromedriver 2.21.371459, chromium: 48.0.2564.116 ... and apparently selenium-webdriver 2.52.0 if you're not careful :+))

[EricHeath-AI]

An env NODE_DEBUG=module ./node_modules/protractor/bin/protractor was somewhat helpful.
With the correct happy setup I see selenium-webdriver loaded from the top of my local: ./node_modules/selenium-webdriver.

With the polluted version where 2.52.0 is in ./node_modules/selenium-webdriver and 2.48.2 is in ./node_modules/protractor/node_modules/selenium-webdriver I see webdriver loaded from both locations: first from ./node_modules/protractor/node_modules/selenium-webdriver (via protractor.js) and then later loaded again from./node_modules/selenium-webdriver via jasminewd2:

Load 1:

DEBUG - Protractor version: 3.1.1
DEBUG - Your base url for tests is https://localhost:9000/
MODULE 906: Module._load REQUEST ./configParser parent: /work/app/node_modules/protractor/lib/taskRunner.js
MODULE 906: RELATIVE: requested: ./configParser set ID to: /work/app/node_modules/protractor/lib/configParser from /work/app/node_modules/protractor/lib/taskRunner.js
MODULE 906: looking for "/work/app/node_modules/protractor/lib/configParser" in ["/work/app/node_modules/protractor/lib"]
MODULE 906: Module._load REQUEST /work/app/protractor.conf.localhost.js parent: /work/app/node_modules/protractor/lib/configParser.jsMODULE 906: looking for "/work/app/protractor.conf.localhost.js" in ["/work/app/node_modules/protractor/lib/node_modules","/work/app/node_modules/protractor/node_modules","/work/app/node_modules","/work/node_modules","/node_modules","/Users/fred/.node_modules","/Users/fred/.node_libraries","/usr/local/lib/node"]
MODULE 906: Module._load REQUEST ./runner parent: /work/app/node_modules/protractor/lib/taskRunner.js
MODULE 906: RELATIVE: requested: ./runner set ID to: /work/app/node_modules/protractor/lib/runner from /work/app/node_modules/protractor/lib/taskRunner.js
MODULE 906: looking for "/work/app/node_modules/protractor/lib/runner" in ["/work/app/node_modules/protractor/lib"]
MODULE 906: load "/work/app/node_modules/protractor/lib/runner.js" for module "/work/app/node_modules/protractor/lib/runner.js"
MODULE 906: Module._load REQUEST ./protractor parent: /work/app/node_modules/protractor/lib/runner.js
MODULE 906: RELATIVE: requested: ./protractor set ID to: /work/app/node_modules/protractor/lib/protractor from /work/app/node_modules/protractor/lib/runner.js
MODULE 906: looking for "/work/app/node_modules/protractor/lib/protractor" in ["/work/app/node_modules/protractor/lib"]
MODULE 906: load "/work/app/node_modules/protractor/lib/protractor.js" for module "/work/app/node_modules/protractor/lib/protractor.js"
MODULE 906: Module._load REQUEST util parent: /work/app/node_modules/protractor/lib/protractor.js
MODULE 906: load native module util
MODULE 906: Module._load REQUEST url parent: /work/app/node_modules/protractor/lib/protractor.js
MODULE 906: load native module url
MODULE 906: Module._load REQUEST selenium-webdriver parent: /work/app/node_modules/protractor/lib/protractor.jsMODULE 906: looking for "selenium-webdriver" in ["/work/app/node_modules/protractor/lib/node_modules","/work/app/node_modules/protractor/node_modules","/work/app/node_modules","/work/node_modules","/node_modules","/Users/fred/.node_modules","/Users/fred/.node_libraries","/usr/local/lib/node"]
MODULE 906: load "/work/app/node_modules/protractor/node_modules/selenium-webdriver/index.js" for module "/work/app/node_modules/protractor/node_modules/selenium-webdriver/index.js"
...

Load 2:

MODULE 906: Module._load REQUEST jasminewd2 parent: /work/app/node_modules/protractor/lib/frameworks/jasmine.js
MODULE 906: looking for "jasminewd2" in ["/work/app/node_modules/protractor/lib/frameworks/node_modules","/work/app/node_modules/protractor/lib/node_modules","/work/app/node_modules/protractor/node_modules","/work/app/node_modules","/work/node_modules","/node_modules","/Users/fred/.node_modules","/Users/fred/.node_libraries","/usr/local/lib/node"]
MODULE 906: load "/work/app/node_modules/jasminewd2/index.js" for module "/work/app/node_modules/jasminewd2/index.js"
MODULE 906: Module._load REQUEST selenium-webdriver parent: /work/app/node_modules/jasminewd2/index.js
MODULE 906: looking for "selenium-webdriver" in ["/work/app/node_modules/jasminewd2/node_modules","/work/app/node_modules","/work/node_modules","/node_modules","/Users/fred/.node_modules","/Users/fred/.node_libraries","/usr/local/lib/node"]
MODULE 906: load "/work/app/node_modules/selenium-webdriver/index.js" for module "/work/app/node_modules/selenium-webdriver/index.js"
MODULE 906: Module._load REQUEST ./builder parent: /work/app/node_modules/selenium-webdriver/index.js
MODULE 906: RELATIVE: requested: ./builder set ID to: /work/app/node_modules/selenium-webdriver/index.js/builder from /work/app/node_modules/selenium-webdriver/index.js
MODULE 906: looking for "/work/app/node_modules/selenium-webdriver/index.js/builder" in ["/work/app/node_modules/selenium-webdriver"]
MODULE 906: load "/work/app/node_modules/selenium-webdriver/builder.js" for module "/work/app/node_modules/selenium-webdriver/builder.js"
MODULE 906: Module._load REQUEST ./chrome parent: /work/app/node_modules/selenium-webdriver/builder.js
MODULE 906: RELATIVE: requested: ./chrome set ID to: /work/app/node_modules/selenium-webdriver/chrome from /work/app/node_modules/selenium-webdriver/builder.js
MODULE 906: looking for "/work/app/node_modules/selenium-webdriver/chrome" in ["/work/app/node_modules/selenium-webdriver"]
MODULE 906: load "/work/app/node_modules/selenium-webdriver/chrome.js" for module "/work/app/node_modules/selenium-webdriver/chrome.js"
...

Not sure if other folks were seeing this exact behaviour, but I hope it helps.

[EricHeath-AI]

fwiw I thought that the second load of the same module via a require('selenium-webdriver') should have resulted in a load from the cache, not the disk per https://nodejs.org/api/modules.html#modules_caching. Maybe it's a bug in node, or maybe I don't get it. (edit: I guess this applies: https://nodejs.org/api/modules.html#modules_module_caching_caveats)

Reading https://github.com/nodejs/node/blob/master/lib/module.js#L285 didn't make my understanding much better. I don't think I would have used the filename as a cache key (the resolve before the cache lookup seems counter-intuitive), but maybe there is a good reason to want to allow multiple copies of things to run in node in certain cases...