Reporter writes spec results out of order

[tbhartman]

Expected behaviour

Reporter should see specs in the order they were defined. I have three groups of four tests which all pass:

  first
    √ 00
    √ 01
    √ 02
    √ 03

  second
    √ 04
    √ 05
    √ 06
    √ 07

  third
    √ 08
    √ 09
    √ 10
    √ 11

Actual behaviour

Reporter sees specs out of order:

  second
    √ 05
    √ 06
    √ 07

  third
    √ 08
    √ 09
    √ 10
    √ 11

  first
    √ 00
    √ 01
    √ 02
    √ 03

  second
    √ 04

Environment Details

• Karma version (output of karma --version): Karma version: 3.1.1
• Relevant part of your karma.config.js file

module.exports = (config) => {
  config.set({
    // karma config
    browsers: ['Chrome'],
    colors: false,
    logLevel: config.LOG_INFO,
    singleRun: true,

    // use jasmine
    frameworks: ['jasmine'],
    client: {jasmine: {random: false}},

    // MRE
    files: ['test.js'],
    reporters: ['spec'],
  })
};

Dump of test.js:

'use strict';

let c = console.log;
let t = setTimeout;

describe('first', ()=>{
  it('00', ()=>{c('start: 00'); c('end:   00');});
  it('01', ()=>{c('start: 01'); c('end:   01');});
  it('02', ()=>{c('start: 02'); c('end:   02');});
  it('03', ()=>{c('start: 03'); c('end:   03');});
});
describe('second', () => {
  it('04', (d)=>{c('start: 04'); t(()=>{c('end:   04'); d();}, 200);});
  it('05', (d)=>{c('start: 05'); t(()=>{c('end:   05'); d();}, 200);});
  it('06', (d)=>{c('start: 06'); t(()=>{c('end:   06'); d();}, 100);});
  it('07', (d)=>{c('start: 07'); t(()=>{c('end:   07'); d();}, 100);});
  // it('04', ()=>{c('start: 04'); c('end: 04');});
  // it('05', ()=>{c('start: 05'); c('end: 05');});
  // it('06', ()=>{c('start: 06'); c('end: 06');});
  // it('07', ()=>{c('start: 07'); c('end: 07');});
});
describe('third', ()=>{
  it('08', ()=>{c('start: 08'); c('end:   08');});
  it('09', ()=>{c('start: 09'); c('end:   09');});
  it('10', ()=>{c('start: 10'); c('end:   10');});
  it('11', ()=>{c('start: 11'); c('end:   11');});
});

I am using karma-spec-reporter, but have reduced it to a bare minimum and still reproduce the problem:

var SpecReporter = function (baseReporterDecorator, formatError, config) {
  baseReporterDecorator(this);
  this.failures = [];
  this.onRunComplete = function (){};
  this.logFinalErrors = function (){};

  this.writeSpecMessage = function (browser, result) {
    var prefix;
    if (result.success) {
      prefix = 'OK';
    } else if (result.skipped) {
      prefix = '--';
    } else {
      prefix = 'KO';
    }
    var spec_name = result.suite.slice();
    spec_name.push(result.description);
    spec_name = spec_name.join(':');
    var msg = prefix + ' ' + spec_name;
    this.writeCommonMsg(msg + '\n');
  };

  this.onBrowserLog = function () {
    this.write('LOG: %s\n', arguments[1]);
  };

  this.specSuccess = this.writeSpecMessage.bind(this);
  this.specSkipped = this.writeSpecMessage.bind(this);
  this.specFailure = this.writeSpecMessage.bind(this);
  this.suppressErrorSummary = true;
  this.showSpecTiming = true;
};

SpecReporter.$inject = ['baseReporterDecorator', 'formatError', 'config'];

module.exports = {
  'reporter:testbug': ['type', SpecReporter]
};

Steps to reproduce the behaviour

1. Copy contents of test.js and karma.conf.js
2. Install karma-spec-reporter
3. run karma start to reproduce
4. switch contents of describe second so all tests are synchronous, and note that order is now correct

Observations

• I only reproduce if some of the tests are asynchronous
• I have not tried without Jasmine (I do not have enough experience with Karma to do so)
• This is not related to Jasmine running tests in random order (reproduced with v2.6.1, and confirmed with log output that tests are run in expected order)

[johnjbarton]

The order of test execution is determined by the test framework, jasmine in your case. Try looking up the issue in jasmine or asking there. Please post back here what you learn: even if we can't help others may have the same issue. Thanks!

[tbhartman]

@johnjbarton, thanks for the quick response. Can you please have a look at my PR #3212. I doubt this is the correct fix, as I'm not sure what is going on with the socket.io.engine.on('upgrade') and why the resultsBufferLimit is reset.

For my test, resultsBufferLimit starts at 50, then gets reset to 1 after spec 04. Thus, all specs before and including 04 are buffered. But since the limit gets reset to 1, those are not flushed until client.complete gets called at the end.

[devoto13]

The fix is almost correct. Tests broke because of JavaScript greatness. Guess what will happen when array is empty?

By default Socket.io would use long polling for communication and then it would upgrade to WebSockets if it is available in the current browser.

Buffering was originally introduced in c4ad697 to workaround reliability issues in some ancient Safari. Not sure if it is necessary anymore, but that's a different story.

This bug was introduced in 603872c. The problem is the race condition between running tests and the Socket.io upgrading to the WebSocket protocol. If test runner reported any results before an upgrade to the WebSocket protocol, they will not be sent to the server until test run is complete.

[karmarunnerbot]

🎉 This issue has been resolved in version 5.0.3 🎉

The release is available on:

• npm package (@latest dist-tag)
• GitHub release

Your semantic-release bot 📦🚀