Feature (logger): disable logs while testing with jest

[IslamWahid]

Description of the feature request

Problem statement

While running jest I would like to suppress the logs on the console to make it readable and clean.

jest CLI is offering --silent option to prevent tests from printing messages through the console, but it doesn't seem to work with the logger.

Summary of the feature

Suggestions:

• the logger is silenced when running in jest with --silent
• the logger is disabled when running in the test environment or when NODE_ENV is a test
• an option on the constructor to disable the logger

Code examples

jest --silent

Benefits for you and the wider AWS community

make the console readable and clean while running tests.

Describe alternatives you've considered

I have created a __mocks__/@aws-lambda-powertools/logger.ts with this setup

export const Logger = jest.fn().mockImplementation(() => {
  return {
    debug: () => jest.fn(),
    info: () => jest.fn(),
    error: () => jest.fn(),
  };
});

and this solves the issue.

Additional context

Related issues, RFCs

[dreamorosi]

Thank you @IslamWahid for opening the issue. I'm going to report part of the content of our discussion on the Slack community channel.

Based on what I could gather, when the --silent flag is present Jest patches the console with a custom version.

On our end, we also don't use the global console because of what described in #748. This most probably impedes Jest to suppress the logs coming from Powertools Logger.

Reproduction example (lib/repro.ts):

import { Logger } from "@aws-lambda-powertools/logger";

const logger = new Logger();

export const handler = async (event: any, _context: any) => {
  logger.info("Hello from Lambda");

  return {
    statusCode: 200,
    body: JSON.stringify({
      message: "Hello World",
    }),
  };
};

And corresponding test (test/repro.test.ts):

import { handler } from "../lib/repro";
import { ContextExamples } from "@aws-lambda-powertools/commons";

describe("MyUnitTest", () => {
  test("Lambda invoked successfully", async () => {
    const testEvent = { test: "test" };
    await handler(testEvent, ContextExamples.helloworldContext);
  });
});

Does in fact generate logs even when using the --silent flag:

 npm run test            

> [email protected] test
> jest --silent

 PASS  test/aws-lambda-powertools-demo.test.ts
{"level":"INFO","message":"Hello from Lambda","service":"service_undefined","timestamp":"2022-07-29T10:13:35.557Z"}

Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        0.621 s, estimated 1 s

Before deciding on whether we should support a way of disabling the logger for unit tests specifically we'd like to hear the opinions of more customers to see if there's demand or if there are other concerns / alternatives to implement it.

In the meantime the pattern that you have described seems like a nice stop-gap solution and perhaps it could make sense to add a mention to it under the "Testing your code" section of the Logger docs (here).

What do you think @saragerion?

[richchurcher]

I'd definitely find this useful. Unit tests can get quite noisy, particularly when testing error cases.

[nathanagez]

I also agree, this can be very useful

[chrisandrewcl]

The logger could just support a special "off" LOG_LEVEL and is up to the user to set it accordingly when needed.

[dreamorosi]

PR #1141 introduces a new environment variable called POWERTOOLS_DEV which is aimed at selectively modifying the behavior of some utilities when developing locally.

The variable at the moment focuses with pretty-printing (i.e. increasing indentation) logs, however once the PR is merged I'll look into whether there's a way of restoring the standard console object when the variable is enabled.

If this is successful, you should be able to use the --silent flag with Jest to suppress logs.

I'll report back once the PR is merged & I have attempted the change.

[dreamorosi]

Leaving here a recap of the discussion plus ideas for the proposed change:

Recap of the current status: As Logger user I would like to suppress logs during testing. Jest supports a --silent flag that allows this, but due to a change we made in #748 to support a different production use case, logger emits logs directly to stdout. This is incompatible with how Jest patches the global console object, which breaks the --silent flag usage (this comment has more details).

Now that we have an environment variable explicitly aimed at local development - POWERTOOLS_DEV (introduced in #1141), we can use this to conditionally set the console back to the global one, kind of like this:

if (POWERTOOLS_DEV === true) this.console = console;

The action here would be:

• Implement this conditional behaviour sometime during class initialisation (the value of the variable is not expected to change at runtime)
• Manually validate that the change works, to do so:
  • run npm pack -w packages/logger (at root folder), this will create a npm module that can be installed
  • in a separate dummy project (you can use this one), install the generated artefact npm i aws-lambda-powertools-logger-1.4.0.tgz
  • then run npm t -> this should generate logs as usual
  • after that run npm t -- --silent this should suppress all logs
• Report on whether the above is successful

[shdq]

@dreamorosi hi, I'm going to look at it and create a PR.

[dreamorosi]

Great thank you @shdq, if you have any questions reach out here or on the #typescript channel on discord

[shdq]

Hi @dreamorosi. I hope you are doing well!

I looked at it and consider two options:

1. "Restore" console

console property initialized as right now and later in setOptions() invoke this.restoreConsoleObj(); to check for POWERTOOLS_DEV inside using getDevMode() and restore this.console = console.

2. "Initialize" console

Similar to envVarsService, it initializes the console property in setOptions() using this.initConsoleObj(); method that will look at POWERTOOLS_DEV and returns console or new Console({ stdout: process.stdout, stderr: process.stderr }).

I implemented and tested both they are working:

I prefer the second one because of its readability. You start reading the code and see the initialization method, look there and understand that the this.console depends on the environment.

But with the second approach and POWERTOOL_DEV=false one test fails:

I tried to find out why and changed expect(parentLogger).toMatchObject(childLogger); to get more details:

Code:

if (!this.getEnvVarsService().getDevMode()) {
  this.console = new Console({ stdout: process.stdout, stderr: process.stderr });
} else {
  this.console = console;
}

Any clues? I haven't found a solution yet. But maybe it isn't needed, and the first option is ok 😉

I'm sorry, but maybe it is a pre-optimization again. I'm asking because if dev mode options (like indentation and suppress logs) keep growing, there are two ways to handle this:

1. Conditionally define every option.
2. Redefine a group of options.

What do you think?

P.S. It makes sense to rename getDevMode() to isDevMode() since it returns boolean.

Have a nice day!

[dreamorosi]

Hi @shdq thank you for looking into the feature!

I agree with you that option 2 is clearer to read, let's go with that option and remove the default value from the Logger class for console.

Let's use your implementation:

if (!this.getEnvVarsService().getDevMode()) {
  this.console = new Console({ stdout: process.stdout, stderr: process.stderr });
} else {
  this.console = console;
}

and place it in a private method which is called from inside setOptions.

Regarding the failing test one, I spent a bit of time looking into the test and I think I have an idea of what is happening:

I put a breakpoint at the failing part of the test and checked the objects & property. As we can see in the screenshot, both parenteLogger.console & childLogeer.console are instances of the class Console, but their identity is not the same.

This is expected since after the proposed change, each time a new instance of Logger is spawned we also initialise a new Console:

this.console = new Console({ stdout: process.stdout, stderr: process.stderr });

Given the above, we could change the line in that unit test like so:

- expect(parentLogger).toEqual(childLogger);
+ expect(childLogger).toEqual({
+     ...parentLogger,
+      console: expect.any(Console),
+ });

In this way we are recursively checking the equality of all properties of childLogger and parentLogger except the console one, which we are manually patching by destructuring the right-side of the comparison.

I should also mention that we have an issue related to these tests (#483) which most probably will require some additional adjustments to these tests, perhaps it could be addressed in one of the next PRs soon.

Finally, related to your last question about renaming getDevMode to isDevMode, yes, let's do it. This would be consistent with a similar function in commons called isColdStart.

[github-actions[bot]]

⚠️ COMMENT VISIBILITY WARNING ⚠️

Comments on closed issues are hard for our team to see. If you need more assistance, please either tag a team member or open a new issue that references this one. If you wish to keep having a conversation with other community members under this issue feel free to do so.