Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

console.* functions called outside tests are not output when singleRun is false #3131

Closed
tbhartman opened this issue Sep 13, 2018 · 16 comments · Fixed by JetBrains/ring-ui#516, Narshe1412/nuarca-sql#25 or karronoli/redpen#10

Comments

@tbhartman
Copy link
Contributor

Expected behaviour

Using client.captureConsole = true, I expect all console.* calls to output to the terminal.

d:\karma_captureConsole_bug> karma start
Chrome 68.0.3440 (Windows 10 0.0.0) INFO: 'I am outside of test!'

LOG: 'I am inside of test!'
Chrome 68.0.3440 (Windows 10 0.0.0): Executed 1 of 1 SUCCESS (0.007 secs / 0.001 secs)
TOTAL: 1 SUCCESS

Actual behaviour

Only console.* calls occurring while running a test are output to the terminal

d:\karma_captureConsole_bug> karma start
LOG: 'I am inside of test!'
Chrome 68.0.3440 (Windows 10 0.0.0): Executed 1 of 1 SUCCESS (0.007 secs / 0.001 secs)
TOTAL: 1 SUCCESS

Environment Details

  • Karma version (output of karma --version): 3.0.0

karma.conf.js:

module.exports = (config) => {
  config.set({
    client: {captureConsole: true},
    frameworks: ['jasmine', 'requirejs'],
    files: ['karma.test.js', 'script.js'],
    browsers: ['Chrome'],
    singleRun: false,
  })
};

karma.test.js:

require.config({
  deps: ['script'],
  callback: window.__karma__.start
});

script.js:

define('script', [], function(){
  console.info('I am outside of test!');
  it('test1', function(){
    console.log('I am inside of test!');
  });
});

Steps to reproduce the behaviour

  1. put above karma.conf.js, karma.test.js, script.js in a directory
  2. run karma start to see actual behavior
  3. change karma.conf.js so that singleRun is true to observe expected behavior
@johnjbarton
Copy link
Contributor

With your singleRun: false setup and no browser set to a karma server URL, issue the karma start command. Of course you should see no logging. Now open a new tab, and open the browser devtools. Then paste the karma server URL. Now you can debug the code path for the outside of the test call.

I guess this is an issue with karma-requirejs project or perhaps karma-jasmine.

@tbhartman
Copy link
Contributor Author

I've confirmed the issue when removing karma-requirejs...I'll check with karma-jasmine.

@pascalpp
Copy link

pascalpp commented Nov 3, 2018

fwiw I'm having this same issue when using karma-mocha as well. console.logs outside of it callbacks are only output when singleRun is true. This was working regardless of the singleRun value when we were using [email protected]. We recently made the jump to [email protected] as part of an upgrade to webpack@4, which is when I noticed this issue. I'm not convinced it has anything to do with the framework adapter (karma-jasmine or karma-mocha), but I'm not intimate with how karma works internally so that's just a hunch, need to dig some more. @tbhartman were you able to find a resolution?

@pascalpp
Copy link

pascalpp commented Nov 3, 2018

using a test file with:

console.log('outside describe')
describe('describe block', function() {
    console.log('inside describe')
    it('it block', function() {
        console.log('inside it')
    })
})

and stepping through the karma versions, I've narrowed down this behavior change as occurring between v2.0.4 and v2.0.5.

in 2.0.4:

START:
PhantomJS 2.1.1 (Mac OS X 0.0.0) LOG: 'outside describe'
PhantomJS 2.1.1 (Mac OS X 0.0.0) LOG: 'inside describe'
LOG: 'inside it'

in 2.0.5:

START:
LOG: 'inside it'

I'll try to compare those releases to see if I can narrow it down further.

@pascalpp
Copy link

pascalpp commented Nov 3, 2018

Narrowed it down to this commit: dc7265b which refactored the READY/CONNECTED state of the browser class.

@pascalpp
Copy link

pascalpp commented Nov 3, 2018

Tinkering in that commit, if I disable the isConnected() check in Browser#onInfo, like so:

  onInfo (info) {
    // if (this.isConnected()) {
    //   return
    // }

...then the logs outside of it blocks are shown in my console even with singleRun: false. I see that in the most recent version, that check has changed to check if (this.isNotConnected()) {.

@johnjbarton can you tell me what purpose that check serves? My understanding is that it's ignoring logs generated during the 'configuring' state. That is, while the spec is being parsed, but before the tests actually start running, it's not emitting the browser_info event so those logs don't appear. It seems to me that those logs should be surfaced regardless of the singleRun setting. (First time really looking at karma source so forgive my naïveté.)

@johnjbarton
Copy link
Contributor

Unfortunately isNotConnected() is confusing; we intended isNotInConnectedState() but I think we should have called it isClientActive().

The code you cite above, from Browser#onInfo, does not match what I see at HEAD:
https://github.com/karma-runner/karma/blob/master/lib/browser.js#L52

When I look at my own test case for global (pre-test) errors, I see events in browser.onKarmaError:
https://github.com/karma-runner/karma/blob/master/lib/browser.js#L43

The info vs error part is determined by the framework adapter code, eg karma-jasmine karma-runner/karma-jasmine#217

@johnjbarton johnjbarton reopened this Nov 6, 2018
@johnjbarton
Copy link
Contributor

Ok I looked into this with our setup and I found that I needed to change Browse.onKarmaError:

onKarmaError (error) {
    if (this.isNotConnected()) {
      this.lastResult.error = true
    }
    this.emitter.emit('browser_error', this, error)
    this.refreshNoActivityTimeout()
  }

I also had to change our reporter to log the error in this case. We have a custom reporter.

I will try to apply this change to karma-runner, but perhaps you can try it and see if it helps.

@pascalpp
Copy link

pascalpp commented Nov 7, 2018

I made a little POC repo https://github.com/pascalpp/karma-console-test and modified that part of lib/browser in place (after installing node_modules). I'm still not seeing the logs after that modification.

@johnjbarton
Copy link
Contributor

Thanks, I tried the repo but

 ./node_modules/karma/bin/karma start
07 11 2018 07:13:18.826:ERROR [karma-server]: Server start failed on port 9876: Error: Cannot find module 'mocha'

@johnjbarton
Copy link
Contributor

install mocha fixes it.

@johnjbarton
Copy link
Contributor

With --logLevel=debug I get

07 11 2018 07:16:54.955:DEBUG [web-server]: serving: /work/karma-console-test/node_modules/karma/static/context.js
07 11 2018 07:16:55.004:DEBUG [phantomjs.launcher]: I am outside of test!

07 11 2018 07:16:55.005:DEBUG [phantomjs.launcher]: I am inside of describe!

07 11 2018 07:16:55.010:DEBUG [phantomjs.launcher]: I am inside of it!

LOG: 'I am inside of it!'
PhantomJS 2.1.1 (Mac OS X 0.0.0): Executed 1 of 1 SUCCESS (0.004 secs / 0 secs)
TOTAL: 1 SUCCESS

@johnjbarton
Copy link
Contributor

The phantomjs.launcher output is just stdout from chrome.

@johnjbarton
Copy link
Contributor

Ok so the issue here is that with singleRun=false the logging arrives in browser.state==1; with singleRun=true the logging arrives in browser.state==2.

@pascalpp
Copy link

pascalpp commented Nov 7, 2018

(oops sorry, forgot to include mocha in the deps, fixed now.)

so the issue here is that with singleRun=false the logging arrives in browser.state==1; with singleRun=true the logging arrives in browser.state==2.

Is that expected, or should it be browser.state == 2 in both cases?

@johnjbarton
Copy link
Contributor

Under singleRun=false we don't call browser.execute():
https://github.com/karma-runner/karma/blob/master/lib/server.js#L248

So we don't enter browser.state=CONFIGURING. Unfortunately the state tracks what the server told the browser to do, rather than the state the browser reports to the server.

I don't see a reason to filter errors based on browser.state. Testing the singleRun=false is hard because the server has to be forced to exit by the test during the test. I'll take one more pass at that.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
3 participants