Cloudwatch - console.log vs console.dir (nodejs lambda)

4

Hello, i have recently used console.dir in our nodejs lambda. I was quite surprised to see that output in CW is different than those of console.log. When i run the same test in nodejs REPL the result is the same.

Lambda test code

const data = {traceId:'de719dc830dd30b74983f14e861ebxxx',parentId:'ae0efdedc04c4xxx',name:'getAllBusinessObjectEventsSpan',id:'85263fd6abb5bxxx',kind:0,timestamp:655413722127740,duration: 4140227,attributes: {},status: { code: 0 },events:[],links: []};

console.log(data);
console.dir(data, { depth: 3});

Result in CW:

  • console.log - there is prefix with timestamp, correlation id and log level (2022-06-29T06:46:05.747Z 9e516xxx-axxx-4xxx-8xxx-xxxxxxxxxxxx INFO) and whole json is written as a single log record (this is expected)
  • console.dir - no prefix is present and each property in json is printed in its own log record (even opening and closing parenthesis)

I thought behaviour should be identical as nodejs REPL yields same results and. Is logging by console.dir not supported in lambdas? Thanks a lot for any ideas

1 Answer
1

Hello,

The Lambda services provided NodeJS runtime will include the timestamp, request ID, and log level when you use console.log although it’s a bit hidden in our documentation: https://docs.aws.amazon.com/lambda/latest/dg/nodejs-logging.html#node-logging-output

It adds a timestamp, request ID, and log level to each entry logged by the function. 

Is the key information. It doesn’t appear we include the same information for console.dir however but you can use the context object to extract the request id, and include timestamps if you want that included in your own console.dir logging.

As far as the differences in the CloudWatch log entries it appears as if it’s more of a NodeJS implementation item instead of anything the Lambdas provided NodeJS runtime is doing; I used three different JSON and it turns out the third one below was written to a single line when viewed in CloudWatch logs:

const data = {traceId:'de719dc830dd30b74983f14e861ebxxx',parentId:'ae0efdedc04c4xxx',name:'getAllBusinessObjectEventsSpan',id:'85263fd6abb5bxxx',kind:0,timestamp:655413722127740,duration: 4140227,attributes: {},status: { code: 0 },events:[],links: []};

const data = {kind:0,timestamp:655413722127740,duration: 4140227,attributes: {},status: { code: 0 },events:[],links: []};

const data = {attributes: {},status: { code: 0 },events:[],links: []};

It looks like depending on the entries found within the JSON it’ll either do multiple entries in a single CloudWatch log entry or a single line. As far as NodeJS REPL I’m not familiar with its underlying implementation myself.

The NodeJS documentation may have some further information on the implementations between the two:

https://nodejs.org/docs/latest/api/console.html#consolelogdata-args

https://nodejs.org/docs/latest/api/console.html#consoledirobj-options

And I think the key item may be console.dir uses util.inspect while I can’t see that console.log does. For a deeper answer that’s more definitive, I’d recommend reaching out to NodeJS folks on their GitHub page (the documentation linked me there): https://github.com/nodejs/node

AWS
SUPPORT ENGINEER
Tim_P
answered 2 years ago
profile picture
EXPERT
reviewed 17 days ago

You are not logged in. Log in to post an answer.

A good answer clearly answers the question and provides constructive feedback and encourages professional growth in the question asker.

Guidelines for Answering Questions