Automatic trace id log injection doesn't work with pino

[oehnstro]

Expected Behavior

The documentation states that the trace id should get automatically injected to the logs for correlation if one is using a supported log library. Pino is listed as a supported library.

Log lines that show up in Datadog should have the trace tab enabled and showing the trace for that request.

Actual Behavior

The START, REPORT and END log-lines that are automatically generated by AWS Lambda have the trace tab enabled and the trace showing, but any manually sent log lines from inside the function don't have any trace id associated with them.

Steps to Reproduce the Problem

We use TypeScript and our logger module looks like this:

import * as pino from 'pino'
import { getConfig } from '../config'

const config = getConfig()

export const logger = pino({
  name: 'service-name',
  level: config.LOG_LEVEL,
  formatters: {
    level(level) {
      return { level }
    }
  }
})

It gets used like this:

import { logger } from '../utils/logger'
...
} catch (error) {
      logger.error(error, `Product error`)
      return null
    }

Specifications

• Datadog Lambda Layer version: 49
• Node version: nodejs12.x
• Lambdas written in TypeScript
• Traces are being sent from the lambda and we can see those in the web console, but they are not linked to any log-lines
• console.log gets the trace id

[amcdnl]

I'm also experiencing this issue.

[maxday]

Can you please share which version of Pino you are using ?

[jsumners]

In my case, I am using ^6.1.0.

[oehnstro]

We use ^6.7.0, but currently we are using console.log in production so I'm not sure if the problem is still there.

[amcdnl]

I'm not sure what i did but this somehow started working for me.

[tianchu]

Here is my testing function using pino@6.13.0:

const logger = require('pino')({
  name: 'pino-test',
  formatters: {
    level(level) {
      return { level }
    }
  }
})

exports.handler = async (event) => {
    logger.error({'user_id': 123}, 'Product error');
    const response = {
        statusCode: 200,
        body: JSON.stringify('Hello from Lambda!'),
    };
    return response;
};

And the log generated in CloudWatch logs do have the corresponding dd attributes, like trace_id, span_id, etc.

{
    "level": "error",
    "time": 1628087986861,
    "pid": 9,
    "hostname": "169.254.123.65",
    "name": "pino-test",
    "user_id": 123,
    "dd": {
        "trace_id": "6746675099437916279",
        "span_id": "6746675099437916279",
        "service": "tc-test-plugin",
        "version": "0.0.1",
        "env": "dev"
    },
    "msg": "Product error"
}

I'm going to close the issue since it seems no longer reproducible.

[oehnstro]

Thank you for looking into this. We are still experiencing the problem. I suppose it most likely has something to do with webpack and/or TypeScript. I've tried disabling minification and using a config as similar as possible to the one you posted, but the log lines sent by Pino still don't get the dd-object. We'll keep using console.log for now and if I have time I'll try to create a minimal setup where this can be reproduced.

[cayter]

Here is my testing function using pino@6.13.0:

const logger = require('pino')({
  name: 'pino-test',
  formatters: {
    level(level) {
      return { level }
    }
  }
})

exports.handler = async (event) => {
    logger.error({'user_id': 123}, 'Product error');
    const response = {
        statusCode: 200,
        body: JSON.stringify('Hello from Lambda!'),
    };
    return response;
};

And the log generated in CloudWatch logs do have the corresponding dd attributes, like trace_id, span_id, etc.

{
    "level": "error",
    "time": 1628087986861,
    "pid": 9,
    "hostname": "169.254.123.65",
    "name": "pino-test",
    "user_id": 123,
    "dd": {
        "trace_id": "6746675099437916279",
        "span_id": "6746675099437916279",
        "service": "tc-test-plugin",
        "version": "0.0.1",
        "env": "dev"
    },
    "msg": "Product error"
}

I'm going to close the issue since it seems no longer reproducible.

@tianchu This is also not working for me, does the library inject dd object locally as well? I have checked the logInjection config is set to true, but I still don't see the dd object being injected locally and production. Does this only work with pino@6.x and not pino@7.x?