Skip to content

feat: logging hook #1114

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 14 commits into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
70 changes: 70 additions & 0 deletions packages/shared/src/hooks/logging-hook.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
import type { OpenFeatureError } from '../errors';
import type { BaseHook } from './hook';
import type { BeforeHookContext, HookContext, HookHints } from './hooks';
import type { FlagValue, EvaluationDetails } from '../evaluation';

import { DefaultLogger, SafeLogger } from '../logger';

type LoggerPayload = Record<string, unknown>;

const DOMAIN_KEY = 'domain';
const PROVIDER_NAME_KEY = 'provider_name';
const FLAG_KEY_KEY = 'flag_key';
const DEFAULT_VALUE_KEY = 'default_value';
const EVALUATION_CONTEXT_KEY = 'evaluation_context';
const ERROR_CODE_KEY = 'error_code';
const ERROR_MESSAGE_KEY = 'error_message';
const REASON_KEY = 'reason';
const VARIANT_KEY = 'variant';
const VALUE_KEY = 'value';

export class LoggingHook implements BaseHook {
readonly includeEvaluationContext: boolean = false;
readonly logger = new SafeLogger(new DefaultLogger(true, true));

constructor(includeEvaluationContext: boolean = false) {
this.includeEvaluationContext = !!includeEvaluationContext;
}

before(hookContext: BeforeHookContext): void {
const payload: LoggerPayload = { stage: 'before' };
this.addCommonProps(payload, hookContext);
this.logger.debug(payload);
}

after(hookContext: Readonly<HookContext<FlagValue>>, evaluationDetails: EvaluationDetails<FlagValue>): void {
const payload: LoggerPayload = { stage: 'after' };

payload[REASON_KEY] = evaluationDetails.reason;
payload[VARIANT_KEY] = evaluationDetails.variant;
payload[VALUE_KEY] = evaluationDetails.value;

this.addCommonProps(payload, hookContext);
this.logger.debug(payload);
}

error(hookContext: Readonly<HookContext<FlagValue>>, error: OpenFeatureError): void {
const payload: LoggerPayload = { stage: 'error' };

payload[ERROR_MESSAGE_KEY] = error.message;
payload[ERROR_CODE_KEY] = error.code;

this.addCommonProps(payload, hookContext);
this.logger.error(payload);
}

finally(hookContext: Readonly<HookContext<FlagValue>>, hookHints?: HookHints): void {
this.logger.info(hookContext, hookHints);
}

private addCommonProps(payload: LoggerPayload, hookContext: HookContext): void {
payload[DOMAIN_KEY] = hookContext.clientMetadata.domain;
payload[PROVIDER_NAME_KEY] = hookContext.providerMetadata.name;
payload[FLAG_KEY_KEY] = hookContext.flagKey;
payload[DEFAULT_VALUE_KEY] = hookContext.defaultValue;

if (this.includeEvaluationContext) {
payload[EVALUATION_CONTEXT_KEY] = hookContext.context;
}
}
}
23 changes: 20 additions & 3 deletions packages/shared/src/logger/default-logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,15 @@
import type { Logger } from './logger';

export class DefaultLogger implements Logger {

private readonly showInfo : boolean = false;
private readonly showDebug : boolean = false;

constructor(showInfo: boolean = false, showDebug: boolean = false){
Copy link
Member

@lukas-reining lukas-reining Dec 19, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

#998 (comment)

Please consider this @kevinmlong.
Having the level configurable via env vars is common and most useful when deployed. Having to rebuild your Dockerfile or even commit a changed log level in case you need to observe something in a deployed instance would not be too practical to me.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lukas-reining - I'm all for being able to pass in configuration from the environment. Perhaps I'm confused though. Wouldn't the applications making use of the hook and the DefaultLogger be where the parameters passed in come from the environment? Perhaps the switch to passing in a LogLevel parameter resolved this as the the client implementation of the SDK would pass in process.env.LOG_LEVEL where appropriate.

Copy link
Member

@lukas-reining lukas-reining Jan 3, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hey sorry for the delay @kevinmlong, I was on vacation :)

Mh, I think the problem to me here is that I could imagine the case of the LoggingHook being registered in every deployment, but it might be preferred to be able to turn on the logging on demand without rebuilding.
If a user deployed a version without explicitly setting a logger, the hook would be statically configured to be in LogLevel.DEBUG.

My idea is that the default OpenFeature logger could just always consume the e.g. OPEN_FEATURE_LOG_LEVEL from the environment variables. With this, the "simple" usage of the hook would always be configurable from the env.
The other approach would require the user to read the env variable, validate it, construct a new logger with it and then create the hook. I find this acceptable but "out-of-the-box configurability" would be nice here.

Another option could be to add a setLogLevel method to the logger interface.
The LoggingHook could then read, parse and validate the e.g. OPEN_FEATURE_LOG_LEVEL from the environment variable and apply it to the configured Logger. Maybe this would be even better in terms of consistency as this would make every logger implementation accept the same env variable through the LoggingHook.

What do you think of these three options? @kevinmlong

cc @toddbaert @beeme1mr

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Many apologies @lukas-reining / @toddbaert / @beeme1mr. It's been a crazy start to the year, and I'm finally finding some time to get back to this.

I'm good with a standard out-of-the-box variable that is read from the environment and defaults to a particular level if not set. I like the idea of doing this via a setLogLevel method on the Logger interface and will give that a whirl.

Copy link
Author

@kevinmlong kevinmlong Feb 13, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lukas-reining - As I started to noodle through this, it occurred to me that "pulling from the environment" would work great on server side use of this, but web apps (e.g., React, Vue) that don't use SSR, are essentially pre-bundled and the "environment" is pre-determined. I'm definitely a fan of config based deployments so that I don't have to re-build stuff to change things like this, but not sure what the best path forward is here. @toddbaert / @beeme1mr - could you weigh in here please?

Copy link
Member

@lukas-reining lukas-reining Feb 13, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

web apps (e.g., React, Vue) that don't use SSR, are essentially pre-bundled and the "environment" is pre-determined

Yeah I did not consider them here, good point! I think it is still fine to change the log behavior during build of the SPA/static web app by setting env variables as this is in-line with some other configs for them. (Enven though many bundlers require a prefix like VITE_)
But it strengthens the point that we need constructor and in my view also env config options. I could also accept leaving the env variable reading to the SDK users but I still support some default.

this.showInfo = showInfo;
this.showDebug = showDebug;
}

error(...args: unknown[]): void {
console.error(...args);
}
Expand All @@ -11,7 +20,15 @@ export class DefaultLogger implements Logger {
console.warn(...args);
}

info(): void {}

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

debug(...args: unknown[]): void {
if(this.showDebug) {
console.debug(...args);
}
}
}
158 changes: 158 additions & 0 deletions packages/shared/test/logger-hook.spec.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,158 @@
import { GeneralError } from '../src/errors';
import type { HookContext } from '../src/hooks/hooks';
import { LoggingHook } from '../src/hooks/logging-hook';
import { DefaultLogger, SafeLogger } from '../src/logger';

describe('LoggingHook', () => {
const FLAG_KEY = 'some-key';
const DEFAULT_VALUE = 'default';
const DOMAIN = 'some-domain';
const PROVIDER_NAME = 'some-provider';
const REASON = 'some-reason';
const VALUE = 'some-value';
const VARIANT = 'some-variant';
const ERROR_MESSAGE = 'some fake error!';
const DOMAIN_KEY = 'domain';
const PROVIDER_NAME_KEY = 'provider_name';
const FLAG_KEY_KEY = 'flag_key';
const DEFAULT_VALUE_KEY = 'default_value';
const EVALUATION_CONTEXT_KEY = 'evaluation_context';
const ERROR_CODE_KEY = 'error_code';
const ERROR_MESSAGE_KEY = 'error_message';

let hookContext: HookContext;
const logger : SafeLogger = new SafeLogger(new DefaultLogger(true, true));

beforeEach(() => {
const mockProviderMetaData = { name: PROVIDER_NAME };

// Mock the hook context
hookContext = {
flagKey: FLAG_KEY,
defaultValue: DEFAULT_VALUE,
flagValueType: 'boolean',
context: { targetingKey: 'some-targeting-key' },
logger: logger,
clientMetadata: { domain: DOMAIN, providerMetadata: mockProviderMetaData },
providerMetadata: mockProviderMetaData,
};

console.debug = jest.fn();
console.warn = jest.fn();
console.info = jest.fn();
console.error = jest.fn();
});

afterEach(() => {
jest.restoreAllMocks();
});

test('should log all props except evaluation context in before hook', () => {
const hook = new LoggingHook(false);

hook.before(hookContext);

expect(console.debug).toHaveBeenCalled();

expect((console.debug as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'before',
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue
});

});

test('should log all props and evaluation context in before hook when enabled', () => {
const hook = new LoggingHook(true);

hook.before(hookContext);

expect(console.debug).toHaveBeenCalled();

expect((console.debug as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'before',
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue,
[EVALUATION_CONTEXT_KEY]: hookContext.context
});

});

test('should log all props except evaluation context in after hook', () => {
const hook = new LoggingHook(false);
const details = { flagKey: FLAG_KEY, flagMetadata: {}, reason: REASON, variant: VARIANT, value: VALUE };

hook.after(hookContext, details);

expect(console.debug).toHaveBeenCalled();

expect((console.debug as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'after',
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue
});
});

test('should log all props and evaluation context in after hook when enabled', () => {
const hook = new LoggingHook(true);
const details = { flagKey: FLAG_KEY, flagMetadata: {}, reason: REASON, variant: VARIANT, value: VALUE };

hook.after(hookContext, details);

expect(console.debug).toHaveBeenCalled();

expect((console.debug as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'after',
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue,
[EVALUATION_CONTEXT_KEY]: hookContext.context
});
});

test('should log all props except evaluation context in error hook', () => {
const hook = new LoggingHook(false);
const error = new GeneralError(ERROR_MESSAGE);

hook.error(hookContext, error);

expect(console.error).toHaveBeenCalled();

expect((console.error as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'error',
[ERROR_MESSAGE_KEY]: error.message,
[ERROR_CODE_KEY]: error.code,
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue,
});
});

test('should log all props and evaluation context in error hook when enabled', () => {
const hook = new LoggingHook(true);
const error = new GeneralError(ERROR_MESSAGE);

hook.error(hookContext, error);

expect(console.error).toHaveBeenCalled();

expect((console.error as jest.Mock).mock.calls[0][0]).toMatchObject({
stage: 'error',
[ERROR_MESSAGE_KEY]: error.message,
[ERROR_CODE_KEY]: error.code,
[DOMAIN_KEY]: hookContext.clientMetadata.domain,
[PROVIDER_NAME_KEY]: hookContext.providerMetadata.name,
[FLAG_KEY_KEY]: hookContext.flagKey,
[DEFAULT_VALUE_KEY]: hookContext.defaultValue,
[EVALUATION_CONTEXT_KEY]: hookContext.context
});
});
});
Loading