refactor: add user-agent parser and introduce new env variables (#122)

* refactor: add user-agent parser and introduce new env variables

* feat: add experimental logtail logger and improve general logger with new options

* chore(refactor): auto format

Signed-off-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>

---------

Signed-off-by: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>

.env.defaults

@@ -8,6 +8,8 @@ TMDB_KEY="TMDB_KEY"
 TRAKT_ID="TRAKT_ID"
 
 GROWTH_KEY="GROWTH_KEY"
+GROWTH_DEV_MODE=false
+GROWTH_TIME_OUT=1000
 
 FEED="FEED"
 YUNA="YUNA"
@@ -19,7 +21,9 @@ SKYHOOK="SKYHOOK"
 TMDB="TMDB"
 TRAKT="TRAKT"
 
-OPTIC_MIN_LEVEL=DEBUG
+MIN_LOG_LEVEL=DEBUG
+OPTIC_TRACING=true
+LOGTAIL_KEY="LOGTAIL_KEY"
 
 UPSTASH_REDIS_REST_URL="UPSTASH_REDIS_REST_URL" 
 UPSTASH_REDIS_REST_TOKEN="UPSTASH_REDIS_REST_TOKEN"

src/common/core/env.ts

@@ -5,7 +5,7 @@ try {
     export: true,
   });
 } catch (_e) {
-  // do nothing
+  throw _e;
 }
 
 export class MissingKeyError extends Error {

src/common/core/factory.ts

@@ -29,12 +29,18 @@ export default (opts: FactoryOptions): Application => {
 
   app.addEventListener('close', (event) => {
     _localSourceFactory.disconnect();
-    logger.info('Request application stop by user', event.type);
+    logger.info(
+      'common:core:factory:close: Request application stop by user',
+      event.type,
+    );
   });
 
   app.addEventListener('error', (event) => {
     _localSourceFactory.disconnect();
-    logger.critical('Uncaught application exception', event.error);
+    logger.critical(
+      'common.core.factory:error: Uncaught application exception',
+      event.error,
+    );
   });
 
   app.use(router.routes());

src/common/core/logger.ts

@@ -1,24 +1,48 @@
 import { SummaryMeasureFormatter } from 'x/optic/profiler';
 import { ConsoleStream, Level, Logger } from 'x/optic';
 import { TokenReplacer } from 'x/optic/formatters';
-//import { RegExpFilter } from 'x/optic/regex-filter';
+import { LogtailStream } from '../logger/logtail.ts';
+import { env } from './env.ts';
+import { MinLogLevel } from '../logger/types.d.ts';
 
-//const regex = RegExp(/[&?]+/);
-//const regExpFilter = new RegExpFilter(regex);
-export const logger = new Logger(); //.addFilter(regExpFilter);
+const consoleLogger = new ConsoleStream()
+  .withFormat(
+    new TokenReplacer()
+      .withFormat('{msg} {metadata}')
+      .withColor(),
+  );
+
+const betterStackLogger = new LogtailStream(
+  env<string>('LOGTAIL_KEY'),
+);
+
+const logLevel = (level: MinLogLevel): Level => {
+  switch (level) {
+    case 'DEBUG':
+      return Level.Debug;
+    case 'INFO':
+      return Level.Info;
+    case 'WARN':
+      return Level.Warn;
+    case 'ERROR':
+      return Level.Error;
+    default:
+      throw new Error('Unkown log level', { cause: level });
+  }
+};
+
+const logger = new Logger()
+  .withMinLogLevel(
+    logLevel(env<MinLogLevel>('MIN_LOG_LEVEL')),
+  )
+  .addStream(consoleLogger)
+  .addStream(betterStackLogger);
 
 logger.profilingConfig()
-  .enabled(true)
+  .enabled(env<boolean>('OPTIC_TRACING'))
   .captureMemory(true)
   .captureOps(true)
   .withLogLevel(Level.Info)
   .withFormatter(new SummaryMeasureFormatter());
 
-logger.addStream(
-  new ConsoleStream()
-    .withFormat(
-      new TokenReplacer()
-        .withFormat('{msg} {metadata}')
-        .withColor(),
-    ),
-);
+export { logger };

src/common/core/setup.ts

@@ -17,17 +17,20 @@ const applicationState: State = {
   features: new GrowthBook({
     apiHost: env<string>('GROWTH'),
     clientKey: env<string>('GROWTH_KEY'),
-    enableDevMode: true,
+    enableDevMode: env<boolean>('GROWTH_DEV_MODE'),
     log: (msg, ctx) => {
       logger.info(msg, ctx);
     },
     trackingCallback: (experiment, result) => {
       // substitute with segment or something else for exp tracking
-      logger.info('Experiemnt tracked', {
+      logger.debug('Experiemnt tracked', {
         experimentId: experiment.key,
         variationId: result.key,
       });
     },
+    onFeatureUsage: (featureKey, result) => {
+      logger.debug('Feature used', { key: featureKey, value: result.value });
+    },
   }),
   contextHeader: {
     agent: '',

src/common/logger/logtail.ts

@@ -0,0 +1,43 @@
+import { Logtail } from 'esm/logtail';
+import { TokenReplacer } from 'x/optic/formatters';
+import { BaseStream, Level, LogRecord } from 'x/optic';
+
+export class LogtailStream extends BaseStream {
+  private logtail: Logtail;
+
+  constructor(clientKey: string) {
+    super(new TokenReplacer());
+    this.logtail = new Logtail(clientKey);
+  }
+
+  log(msg: string): void {
+    this.logtail.log(msg);
+    this.logtail.flush();
+  }
+
+  override handle(logRecord: LogRecord): boolean {
+    const { level, metadata } = logRecord;
+    if (this.minLevel > level) return false;
+    const msg = this.format(logRecord);
+
+    switch (level) {
+      case Level.Info:
+        this.logtail.info(msg, { ...metadata });
+        break;
+      case Level.Warn:
+        this.logtail.warn(msg, { ...metadata });
+        break;
+      case Level.Error:
+        this.logtail.error(msg, { ...metadata });
+        break;
+      case Level.Critical:
+        this.logtail.log(msg, 'fatal', { ...metadata });
+        break;
+      default:
+        return false;
+    }
+
+    this.logtail.flush();
+    return true;
+  }
+}

src/common/logger/types.d.ts

@@ -0,0 +1 @@
+export type MinLogLevel = 'DEBUG' | 'INFO' | 'WARN' | 'ERROR';

src/common/middleware/growth.ts

@@ -1,21 +1,36 @@
 import { between } from 'x/optic';
 import { logger } from '../core/logger.ts';
 import type { AppContext } from '../types/core.d.ts';
+import { env } from '../core/env.ts';
 
 export default async (
   { state }: AppContext,
   next: () => Promise<unknown>,
 ) => {
   logger.mark('load-features-start');
   await state.features.init({
-    timeout: 2000,
+    timeout: env<number>('GROWTH_TIME_OUT'),
   })
-    .then(() => {
+    .then((data) => {
+      if (data.error) {
+        logger.error(
+          'common.middleware.growth: GrowthBook init error',
+          data.error,
+        );
+      } else {
+        logger.info(
+          'common.middleware.growth: GrowthBook init complete',
+          data.source,
+        );
+      }
       logger.mark('load-features-end');
       logger.measure(between('load-features-start', 'load-features-end'));
     })
     .catch((e) => {
-      logger.error('Failed to load features from GrowthBook', e);
+      logger.error(
+        'common.middleware.growth: Failed to load features from GrowthBook',
+        e,
+      );
     })
     .finally(async () => {
       await next();
@@ -27,6 +42,6 @@ export default async (
       logger.measure(between('destory-growth-start', 'destory-growth-end'));
     })
     .catch((e) => {
-      logger.error('Failed to destory GrowthBook', e);
+      logger.error('common.middleware.growth: Failed to destory GrowthBook', e);
     });
 };

src/common/middleware/header.ts

@@ -16,14 +16,12 @@ const optional: string[] = [
   'x-app-source',
   'x-app-locale',
   'x-app-build-type',
-  'x-forwarded-for',
 ];
 
 const enforced: string[] = [
   'host',
   'accept',
   'accept-encoding',
-  'accept-language',
   'user-agent',
 ];
 
@@ -34,22 +32,21 @@ const fail = (header: string, ctx: AppContext) => {
   response.body = <Error> {
     message: 'Missing required header',
   };
-  logger.error(`Required header is missing from request: ${header}`);
+  logger.error(
+    `common.middleware.header:fail: Required header is missing from request: ${header}`,
+  );
 };
 
 const pass = async (ctx: AppContext, next: () => Promise<unknown>) => {
   const { state, request } = ctx;
   const { headers } = request;
 
-  const userAgent = headers.get('user-agent') ?? null;
-
   state.contextHeader = {
     authorization: headers.get('authorization'),
     accepts: ctx.request.accepts()!,
-    agent: userAgent,
+    agent: headers.get('user-agent')!,
     contentType: headers.get('content-type'),
     acceptEncoding: headers.get('accept-encoding')!,
-    language: headers.get('accept-language')!,
     application: {
       locale: headers.get('x-app-locale'),
       version: headers.get('x-app-version'),
@@ -59,6 +56,7 @@ const pass = async (ctx: AppContext, next: () => Promise<unknown>) => {
       buildType: headers.get('x-app-build-type'),
     },
   };
+  logger.debug('common.middleware.header:pass: ->', state.contextHeader);
   await next();
 };
 

src/common/middleware/targeting.ts

@@ -1,14 +1,16 @@
 import { between } from 'x/optic';
+import { State } from '../types/state.d.ts';
+import { UAParser } from 'esm/ua_parser';
 import { logger } from '../core/logger.ts';
 import type { AppContext } from '../types/core.d.ts';
 
-export default async (
-  { state }: AppContext,
-  next: () => Promise<unknown>,
-) => {
-  logger.mark('set-attributes-start');
-  const { application, agent } = state.contextHeader;
+const contextAttributes = (
+  { contextHeader }: State,
+): Promise<Record<string, unknown>> => {
+  const { application, agent } = contextHeader;
+
   let attributes: Record<string, unknown> = {};
+
   if (application) {
     attributes = {
       'app_version': application.version,
@@ -19,15 +21,40 @@ export default async (
       'app_locale': application.locale,
     };
   }
-  await state.features.setAttributes({
-    'user_agent': agent,
+
+  const parser = new UAParser(agent);
+  const { browser, cpu, device, engine, os } = parser.getResult();
+
+  return Promise.resolve({
+    'browser_name': browser.name,
+    'browser_version': browser.version,
+    'cpu_architecture': cpu.architecture,
+    'device_model': device.model,
+    'device_vendor': device.vendor,
+    'device_type': device.type,
+    'engine_name': engine.name,
+    'engine_version': engine.version,
+    'os_name': os.name,
+    'os_version': os.version,
     ...attributes,
-  }).then(() => {
-    logger.mark('set-attributes-end');
-    logger.measure(between('set-attributes-start', 'set-attributes-end'));
+  });
+};
+
+export default async (
+  { state }: AppContext,
+  next: () => Promise<unknown>,
+) => {
+  logger.mark('set-attributes-start');
+  await contextAttributes(state).then(async (data) => {
+    await state.features.setAttributes(data).then(() => {
+      logger.mark('set-attributes-end');
+      logger.measure(between('set-attributes-start', 'set-attributes-end'));
+    }).catch((e) => {
+      logger.error('set-attributes encountered an error', e);
+    }).then(async () => {
+      await next();
+    });
   }).catch((e) => {
-    logger.error('set-attributes encountered an error', e);
-  }).finally(async () => {
-    await next();
+    logger.error('contextAttributes encountered an error', e);
   });
 };