[FEATURE] Implement logging hook

[toddbaert]

Requirements

• Implement a logging hook as described in appendix A of the OpenFeaure spec: https://github.com/open-feature/spec/blob/main/specification/appendix-a-included-utilities.md#logging-hook
• Remove all logging from evaluation lifecycle (hot path)

Java implementation: open-feature/java-sdk#1084

[Rahilsiddique]

So what I understand is that we have to create a hook that will be used to log the messages during flag life-cycle
i.e before, after, error and finally
Hey I would like to give it a try 🤚
Thanks !

[toddbaert]

So what I understand is that we have to create a hook that will be used to log the messages during flag life-cycle i.e before, after, error and finally Hey I would like to give it a try 🤚 Thanks !

Yep - and also remove any non-debug logging in hot code-paths.

[beeme1mr]

Hi @Rahilsiddique, is this something you're still interested in working on?

[kevinmlong]

@beeme1mr / @toddbaert - I'm happy to take this issue on as my first issue. I can target a few weeks to have a PR opened for folks to take a look at.

[beeme1mr]

Thanks @kevinmlong!

[kevinmlong]

@beeme1mr / @toddbaert - trying to understand a few things when working on this issue.

It appears that DefaultLogger doesn't actually log anything when info or debug are called. Looking at the linked implementation from the Java SDK, it use debug for before and after. Pretty easy to fill out the implementation, but then this causes the a few tests to fail. What's the reasoning here for why console.info and console.debug shouldn't be used for the respective implementations in DefaultLogger?

[kevinmlong]

Looking at the spec (https://github.com/open-feature/spec/blob/main/specification/appendix-a-included-utilities.md#logging-hook) seems we should be using debug and info for these stages as well, so perhaps we should have the DefaultLogger implement these.

[beeme1mr]

console.debug is an alias for console.log in node.js. That's why we decided to no-op debug by default. In this case, debug feels like the correct log level but it would definitely be annoying to see nothing if you're using the default logger. @toddbaert @lukas-reining, would either of you have a suggestion?

[kevinmlong]

Understood on the alias for debug, but seems that if we're providing the debug method it should probably do something. For now, I implemented a VerboseLogger that implements all log levels and this is what the LoggerHook uses when instantiating an instance of SafeLogger.

import type { Logger } from './logger';

export class VerboseLogger implements Logger {
  error(...args: unknown[]): void {
    console.error(...args);
  }

  warn(...args: unknown[]): void {
    console.warn(...args);
  }

  info(...args: unknown[]): void {
    console.info(...args);
  }
  
  debug(...args: unknown[]): void {
    console.debug(...args);
  }
}

import { VerboseLogger, SafeLogger } from '../logger';
...
export class LoggingHook implements BaseHook {
  readonly includeEvaluationContext: boolean = false;
  readonly logger = new SafeLogger(new VerboseLogger());
  ...
}

[lukas-reining]

console.debug is an alias for console.log in node.js. That's why we decided to no-op debug by default. In this case, debug feels like the correct log level but it would definitely be annoying to see nothing if you're using the default logger. @toddbaert @lukas-reining, would either of you have a suggestion?

Understood on the alias for debug, but seems that if we're providing the debug method it should probably do something. For now, I implemented a VerboseLogger that implements all log levels and this is what the LoggerHook uses when instantiating an instance of SafeLogger.

import type { Logger } from './logger';

export class VerboseLogger implements Logger {
  error(...args: unknown[]): void {
    console.error(...args);
  }

  warn(...args: unknown[]): void {
    console.warn(...args);
  }

  info(...args: unknown[]): void {
    console.info(...args);
  }
  
  debug(...args: unknown[]): void {
    console.debug(...args);
  }
}

import { VerboseLogger, SafeLogger } from '../logger';
...
export class LoggingHook implements BaseHook {
  readonly includeEvaluationContext: boolean = false;
  readonly logger = new SafeLogger(new VerboseLogger());
  ...
}

I think so too @kevinmlong. When using the logging hook, i think it is safe to assume that everything that was given to debug should also be seen.
So I think this is a good way forward.

But I think it would make sense to not go for a VerboseLogger but rather add a defined environment variable and/or configuration in the constructor to set the log level.
I think we should go for both, but especially the env variable would be important to have when a deployed service has issues and you want to turn on the logging without rebuilding.
cc @toddbaert @beeme1mr

[toddbaert]

I think so too @kevinmlong. When using the logging hook, i think it is safe to assume that everything that was given to debug should also be seen. So I think this is a good way forward.

💯

But I think it would make sense to not go for a VerboseLogger but rather add a defined environment variable and/or configuration in the constructor to set the log level. I think we should go for both, but especially the env variable would be important to have when a deployed service has issues and you want to turn on the logging. cc @toddbaert @beeme1mr

We could do this, and maybe make the level info by default. With the other changes in this PR (not logging at all during hot paths) that might be OK.

[kevinmlong]

@beeme1mr / @toddbaert - I started a draft PR (#1114) for the LoggingHook implementation. I could use some guidance on the "hot path" and what that means.

[beeme1mr]

Hey @kevinmlong, a "hot path" is the code executed during a feature flag evaluation. Examples of non-hot paths would be registering a provider or hook. Basically, we're trying not to spam logs for actions that could happen at high frequency.