Karma: Undocumented breaking change

[ykosbie]

Expected behaviour

2228 extended browserConsoleLogOptions.level to filter messages on the terminal. This changes the behavior of karma so that under certain circumstances messages created with console no longer show up in the terminal without configuration changes. This should be documented.

Actual behaviour

There is no documentation. In my case I spent over 3 hours investigating source code, git issues, versions, etc before I identified the problem was this change.

Environment Details

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

[dignifiedquire]

Log levels keep on giving. I am sorry about that. @wesleycho could you do a small write up about the old vs the new behaviour, that we can put into the changelog?

[wesleycho]

Sure, how should I do so - should I modify the changelog?

[robsimmons]

The new behavior doesn't seem like it could be consistent with the _debug info log warn error_ ordering of console verbosity that the previous ticket claimed. If I include this in a spec:

console.debug("AAA");
console.info("BBB");
console.log("CCC");
console.warn("DDD");
console.error("EEE");

then as of 1.5.0, on the command line I get

DEBUG: 'AAA'
INFO: 'BBB'
WARN: 'DDD'
ERROR: 'EEE'

The string browserConsoleLogOptions only appears under ./node_modules/karma.

[robsimmons]

To be clear, "the ordering that the previous ticket claimed" refers to @dignifiedquire's comment on December 7 to #2228.

[s100]

Yes, it seems that in practice the order of decreasing verbosity/increasing severity is now log, debug, info, warn, error. Since the default value of browserConsoleLogOptions.level is "debug", this means that anybody not using this option will no longer see console.log entries at all.

A workaround is to set browserConsoleLogOptions.level to "log".

[mgol]

Chrome has 4 levels of filtering output in a console: Verbose, Info, Warnings & Errors. Choosing Errors just enables console.error, choosing Warnings enables console.error & console.warn, choosing Info enables everything except console.debug and choosing Verbose enables anything.

This means while the order between LOG & INFO is not clear, they both should definitely be closer to ERROR than DEBUG and now LOG is treated as the most verbose option.

I'd advocate for the order:

exports.LOG_DISABLE
exports.LOG_ERROR
exports.LOG_WARN
exports.LOG_INFO
exports.LOG_LOG
exports.LOG_DEBUG

Also, currently (in 1.5.0) even setting logLevel in the Karma config doesn't show console.logs so we have 2 bugs here...

[robsimmons]

This doc (and I've found at least one other) says that Log + Debug are exact aliases, so contrary to what the previous issue said (and what I was kind of advocating for above), putting Info between Log and Debug probably isn't justifable. So either log > debug, log = debug, or log < debug is justifiable, but the issue at present is that the behavior introduced in 1.4.1 -> 1.5.0 wasn't backward-compatible.

[mgol]

@robsimmons What I proposed fits passes your criteria regarding the desired order. If we're talking compatibility breaks, though, previously LOG_INFO printed console.logs and now it doesn't so to be backwards compatible the order would have to be:

exports.LOG_DISABLE
exports.LOG_ERROR
exports.LOG_WARN
exports.LOG_LOG
exports.LOG_INFO
exports.LOG_DEBUG

[dignifiedquire]

So if I understand it correctly, if we move to the last option @mgol proposed brings the default behaviour back to what it was before, while matching the general expectations for the various values that can be set. Could I get some confirmation for that?

[robsimmons]

@dignifiedquire I believe that's mostly right. The sadness is there has to be a choice between backwards compatibility and complying with the spec that Console.log === Console.debug.

There's a separate and not-cleanly-answerable question of whether "general expectations" match the spec. I suspect the ordering disable / error / warn / log / info / debug may be both "incorrect" and "generally expected."

[ykosbie]

@robsimmons @dignifiedquire I first encountered this issue b/c I was working w/ the expectation that log != debug. console.log is used as the default "write output the screen" in most tutorials I've seen. It's even used in the official jasmine docs. According to the spec, most of these cases should be using console.info but I have never seen it used that way.

[mgol]

@dignifiedquire Is there any other doubt here on what should be done? If my list sounds OK I can submit a PR; it'd be good to get this regression resolved.

[dignifiedquire]

@mgol yes lets go with that please so we can unbreak peoples code

[mgol]

@dignifiedquire I wanted to land a fix with tests but it seems tests in @blackswanny's commit 89a7a1cce68246c620f9959ee31133bfa42be5dc don't actually test what they're supposed to - the spies never fire even if you change the parameters passed to reporter.onBrowserLog to use a higher priority than the one set in browserConsoleLogOptions... :/ Any ideas on what they should look like?

[mgol]

OK, I managed to fix existing tests and then fixed this issue; PR #2676.

[mgol]

@dignifiedquire could you release a new version?

[yavin5]

Here are exact configuration changes that should work (works great for me after these changes):

• Edit your karma.conf.js file to add some configuration directives under the "config.set({" line.
• There should be a "client:" section, and inside that you need to add "captureConsole: true" like this:

client: {
    captureConsole: true
  }

.. Make sure you put a comma after the word "true" if there are additional directives after the captureConsole line.

• Add "browserConsoleLogOptions:" section, if there isn't already one in the file, preferably just after the "client:" section. Make it look like this:

    browserConsoleLogOptions: {
      level: 'log',
      format: '%b %T: %m',
      terminal: true
    },

.. The comma on the ending line is there because we will add one more section after that.
* Add a "logLevel:" section if there isn't already one in the file, preferably just after the "browserConsoleLogOptions:" section we just added. Make it look like this:
logLevel: config.LOG_LOG
Make sure you put a comma on the end of that line if there are additional config directives after this line.
- Rebuild.
- Restart Karma.

Then, whenever your test does:

console.log('TEST OUTPUT.');

.. you should see the output. Other console log levels should also work.

[stevenvachon]

I still see no logs from the browser.

[CHBaker]

I second @stevenvachon, I followed @yavin5 exactly and I still can't see logs in the browser or terminal,
these are my versions:

"@types/jasmine": "~2.6.0",
    "@types/jasminewd2": "~2.0.3",
    "@types/node": "~8.0.34",
    "codelyzer": "~3.0.1",
    "jasmine-core": "~2.9.0",
    "jasmine-spec-reporter": "~4.2.1",
    "karma": "^1.7.1",
    "karma-chrome-launcher": "~2.2.0",
    "karma-cli": "~1.0.1",
    "karma-coverage-istanbul-reporter": "^1.3.0",
    "karma-jasmine": "~1.1.0",
    "karma-jasmine-html-reporter": "^0.2.2",

and this is my config:

config.set({
    basePath: '',
    frameworks: ['jasmine', '@angular/cli'],
    plugins: [
      require('karma-jasmine'),
      require('karma-chrome-launcher'),
      require('karma-jasmine-html-reporter'),
      require('karma-coverage-istanbul-reporter'),
      require('@angular/cli/plugins/karma')
    ],
    client:{
      clearContext: false, // leave Jasmine Spec Runner output visible in browser
      captureConsole: true
    },
    coverageIstanbulReporter: {
      reports: [ 'html', 'lcovonly' ],
      fixWebpackSourcePaths: true
    },
    angularCli: {
      environment: 'dev'
    },
    browserConsoleLogOptions: {
        level: 'log',
        format: '%b %T: %m',
        terminal: true
    },
    logLevel: config.LOG_LOG,
    reporters: ['progress', 'kjhtml'],
    port: 9876,
    colors: true,
    autoWatch: true,
    browsers: ['Chrome'],
    singleRun: false,
    captureTimeout: 240000, // it was already there
    browserDisconnectTimeout : 10000,
    browserDisconnectTolerance : 1,
    browserNoActivityTimeout : 60000,//by default 10000

in my browser I'm getting:
_Console was cleared_ karma.js:205 <-- could this have something to do with it?

[blackswanny]

@stevenvachon @CHBaker "from" or "in" browser?
browserConsoleLogOptions config affects only logs captured in karma.
afaik only those in terminal, cause karma is able to intercept them there. In browser, we need to check. For phantom it worked well. Karma may not capture logs in other browsers, or if sub library, like jasmine, etc uses something else than 'console' api to do so.

[stevenvachon]

My issue has been resolved. Native console.log was replaced with a custom implementation.

[CHBaker]

@blackswanny I cannot see my logs in the browser or the terminal. I'm using Karma, Jasmine, and Angular 5, with Chrome latest. Only console.logs outside karma (meaning the ones in the functions I am testing) get logged in the terminal _and_ the browser.

I have attempted usingconsole.debug, and console.info, but those get errors saying

calls to 'console.debug/info' are not allowed. (no-console)

[RichieRunner]

@CHBaker Same, I'm getting a "Console Was Cleared" as well in chrome browser. Followed all the instructions above.

[chris-ch]

Same problem here

[jjinux]

BTW, @chris-ch, this configuration worked for me:

browserConsoleLogOptions: {
    level: 'log',
    format: '%b %T: %m',
    terminal: true,
},
client: {
    captureConsole: true,
},
logLevel: 'LOG',

I'm using Karma 1.7.1.