Ava: Make t.log() behave like console.log()

[edbrannin]

Description

When using --tap output, trying to log an object results in an error. Worse, the stack trace points to ava internals, not to my test code.

If t.log is given an object:

• Minimum expected behavior: Throw immediately
• Preferred expected behavior: Pass through JSON.stringify(arg, null, 2)

I do a lot of t.log(JSON.stringify(resp.body, null, 2)); and it would be great to just say t.log(resp.body); instead.

Test Source

import { serial as test } from 'ava';

test('Log an object', (t) => {
  const myObject = { a: 1 };
  t.log(myObject);
  t.is(true, true);
});

Error Message & Stack Trace

^^/d/o/b/ava >>> ava --tap test.js 

/Users/redacted/dev/oss/bug-reports/ava/node_modules/indent-string/index.js:9
        throw new TypeError(`Expected \`input\` to be a \`string\`, got \`${typeof str}\``);
        ^

TypeError: Expected `input` to be a `string`, got `object`
    at module.exports (/Users/redacted/dev/oss/bug-reports/ava/node_modules/indent-string/index.js:9:9)
    at test.logs.forEach.log (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/reporters/tap.js:64:23)
    at Array.forEach (<anonymous>)
    at appendLogs (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/reporters/tap.js:63:15)
    at TapReporter.test (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/reporters/tap.js:83:4)
    at Logger.test (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/logger.js:27:28)
    at emitTwo (events.js:126:13)
    at RunStatus.emit (events.js:214:7)
    at RunStatus.handleTest (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/run-status.js:105:8)
    at emitOne (events.js:121:20)
    at ChildProcess.emit (events.js:211:7)
    at ChildProcess.ps.on.event (/Users/redacted/dev/oss/bug-reports/ava/node_modules/ava/lib/fork.js:79:7)
    at emitTwo (events.js:126:13)
    at ChildProcess.emit (events.js:214:7)
    at emit (internal/child_process.js:772:12)
    at _combinedTickCallback (internal/process/next_tick.js:141:11)

Config

N/A. Here's my test package.json:

{
  "name": "ava-bug-report",
  "version": "1.0.0",
  "description": "Reporting an issue in ava",
  "main": "test.js",
  "author": "Ed Brannin",
  "license": "MIT",
  "private": true,
  "dependencies": {
    "ava": "^0.24.0"
  }
}

Command-Line Arguments

Copy your npm build scripts or the ava command used:

ava --tap test.js

Relevant Links

https://github.com/edbrannin/ava-issue-1635

Environment

Tell us which operating system you are using, as well as which versions of Node.js, npm, and AVA. Run the following to get it quickly:

Node.js v8.9.0
darwin 16.7.0
0.24.0
5.6.0

[novemberborn]

@edbrannin, thanks, that's a good catch.

t.log() currently only accepts strings. At the very least we should throw immediately when called without a string.

Expanding support for logging non-strings makes sense too. We should use the same formatting as we do for other values (this line, basically). Would folks want to log more than one argument in that case?

[sindresorhus]

Would folks want to log more than one argument in that case?

Yes, most are used to console.log where this is possible, and it's very useful too.

[kugtong33]

@novemberborn , i'll give this a try :+1:

[kugtong33]

@vadimdemedes , will this be covered on your WIP task?

@novemberborn @vadimdemedes , I will still write my thoughts here, on what I understood and if I have the correct context of the problem, to have feedback from you guys as I just started digging up the codes :)

[novemberborn]

@kugtong33 #1645 does not impact this.

I will still write my thoughts here, on what I understood and if I have the correct context of the problem, to have feedback from you guys as I just started digging up the codes :)

👍

[kugtong33]

@novemberborn @vadimdemedes

So I tried all reporters, tap, mini, and verbose

import test from 'ava';

test('Log an object', (t) => {
  t.log('sample string log');
  t.log({ a: 1 });
  t.is(true, true);
});

/* mini only shows logs when it fails */
  1 failed

  Log an object
    ℹ sample string log
    ℹ [object Object]

  /github/ava-labs/test/log.test.js:6

   5:   t.log({ a: 1 });
   6:   t.fail();       
   7: });               

  Test failed via `t.fail()`

/* verbose reporter */
  ✔ Log an object
    ℹ sample string log
    ℹ [object Object]

  1 test passed

/* tap throws an error as described by the issue */

Logs are stored in an array as I have seen in here and is directly fed into supertap here which should be an array of strings as its documentation said.

If we want it to behave the same as console.log we can format the arguments and append all of them on a single string before pushing it to the logs array here

Does it sound right?

[novemberborn]

If we want it to behave the same as console.log we can format the arguments and append all of them on a single string before pushing it to the logs array here

Does it sound right?

Yes. We should use the same formatting as we do for other values (this line, basically).

[kugtong33]

@novemberborn , I also found this

import test from 'ava';

test('Log an object', (t) => {
  t.log();
  t.is(true, true);
});

/* verbose */
  ✔ Log an object
    ℹ null

  1 test passed

/* mini when test fails */
  Log an object
    ℹ null

  /github/ava-labs/test/log.test.js:5

   4:   t.log(); 
   5:   t.fail();
   6: });

/* tap */
TAP version 13
/github/ava-labs/node_modules/indent-string/index.js:9
        throw new TypeError(`Expected \`input\` to be a \`string\`, got \`${typeof str}\``);
        ^

TypeError: Expected `input` to be a `string`, got `object`
    at module.exports (/github/ava-labs/node_modules/indent-string/index.js:9:9)
    at test.logs.forEach.log (/github/ava-labs/node_modules/ava/lib/reporters/tap.js:64:23)
    at Array.forEach (<anonymous>)
    at appendLogs (/github/ava-labs/node_modules/ava/lib/reporters/tap.js:63:15)
    at TapReporter.test (/github/ava-labs/node_modules/ava/lib/reporters/tap.js:83:4)
    at Logger.test (/github/ava-labs/node_modules/ava/lib/logger.js:27:28)
    at emitTwo (events.js:126:13)
    at RunStatus.emit (events.js:214:7)
    at RunStatus.handleTest (/github/ava-labs/node_modules/ava/lib/run-status.js:105:8)
    at emitOne (events.js:121:20)
    at ChildProcess.emit (events.js:211:7)
    at ChildProcess.ps.on.event (/github/ava-labs/node_modules/ava/lib/fork.js:79:7)
    at emitTwo (events.js:126:13)
    at ChildProcess.emit (events.js:214:7)
    at emit (internal/child_process.js:772:12)
    at _combinedTickCallback (internal/process/next_tick.js:141:11)

[edbrannin]

@kugtong33 ...and we've come full-circle to the error that prompted this issue. :)