feat(filters): log the matching status of each filter

diff.txt

@@ -0,0 +1,314 @@
+diff --git a/src/filters.ts b/src/filters.ts
+index 8c878d7..28a5c5f 100644
+--- a/src/filters.ts
++++ b/src/filters.ts
+@@ -17,15 +17,54 @@
+  */
+ import { b64UrlToUtf8, fromB64Url, sha256B64Url } from './lib/encoding.js';
+ import { ItemFilter, MatchableItem } from './types.js';
++import { Logger } from 'winston';
++
++const logMatchResult = ({
++  log,
++  item,
++  isMatching,
++}: {
++  log: Logger;
++  item: MatchableItem;
++  isMatching: boolean;
++}) => {
++  if (isMatching) {
++    log.debug('filter is matching', {
++      id: item.id,
++      height: item.height,
++      parent: item.parent_id,
++    });
++  } else {
++    log.debug('filter is not matching', {
++      id: item.id,
++      height: item.height,
++      parent: item.parent_id,
++    });
++  }
++};
+
+ export class AlwaysMatch implements ItemFilter {
+-  async match(_: MatchableItem): Promise<boolean> {
++  private log: Logger;
++
++  constructor(log: Logger) {
++    this.log = log.child({ class: 'AlwaysMatch' });
++  }
++
++  async match(item: MatchableItem): Promise<boolean> {
++    logMatchResult({ log: this.log, item, isMatching: true });
+     return true;
+   }
+ }
+
+ export class NeverMatch implements ItemFilter {
+-  async match(_: MatchableItem): Promise<boolean> {
++  private log: Logger;
++
++  constructor(log: Logger) {
++    this.log = log.child({ class: 'NeverMatch' });
++  }
++
++  async match(item: MatchableItem): Promise<boolean> {
++    logMatchResult({ log: this.log, item, isMatching: false });
+     return false;
+   }
+ }
+@@ -33,20 +72,27 @@ export class NeverMatch implements ItemFilter {
+ export class NegateMatch implements ItemFilter {
+   private readonly filter: ItemFilter;
+
+-  constructor(filter: ItemFilter) {
++  private log: Logger;
++
++  constructor(filter: ItemFilter, log: Logger) {
+     this.filter = filter;
++    this.log = log.child({ class: 'NegateMatch' });
+   }
+
+   async match(item: MatchableItem): Promise<boolean> {
+-    return !(await this.filter.match(item));
++    const isMatching = !(await this.filter.match(item));
++    logMatchResult({ log: this.log, item, isMatching });
++    return isMatching;
+   }
+ }
+
+ export class MatchAll implements ItemFilter {
+   private readonly filters: ItemFilter[];
++  private log: Logger;
+
+-  constructor(filters: ItemFilter[]) {
++  constructor(filters: ItemFilter[], log: Logger) {
+     this.filters = filters;
++    this.log = log.child({ class: 'MatchAll' });
+   }
+
+   async match(item: MatchableItem): Promise<boolean> {
+@@ -54,15 +100,19 @@ export class MatchAll implements ItemFilter {
+       this.filters.map((filter) => filter.match(item)),
+     );
+
+-    return results.every((result) => result);
++    const isMatching = results.every((result) => result);
++    logMatchResult({ log: this.log, item, isMatching });
++    return isMatching;
+   }
+ }
+
+ export class MatchAny implements ItemFilter {
+   private readonly filters: ItemFilter[];
++  private log: Logger;
+
+-  constructor(filters: ItemFilter[]) {
++  constructor(filters: ItemFilter[], log: Logger) {
+     this.filters = filters;
++    this.log = log.child({ class: 'MatchAny' });
+   }
+
+   async match(item: MatchableItem): Promise<boolean> {
+@@ -70,7 +120,9 @@ export class MatchAny implements ItemFilter {
+       this.filters.map((filter) => filter.match(item)),
+     );
+
+-    return results.some((result) => result);
++    const isMatching = results.some((result) => result);
++    logMatchResult({ log: this.log, item, isMatching });
++    return isMatching;
+   }
+ }
+
+@@ -88,9 +140,11 @@ type TagMatch = TagValueMatch | TagValueStartsWithMatch;
+
+ export class MatchTags implements ItemFilter {
+   private readonly tags: TagMatch[];
++  private log: Logger;
+
+-  constructor(tags: TagMatch[]) {
++  constructor(tags: TagMatch[], log: Logger) {
+     this.tags = tags;
++    this.log = log.child({ class: 'MatchTags' });
+   }
+
+   async match(item: MatchableItem): Promise<boolean> {
+@@ -119,15 +173,19 @@ export class MatchTags implements ItemFilter {
+       }
+     }
+
+-    return matches.size === this.tags.length;
++    const isMatching = matches.size === this.tags.length;
++    logMatchResult({ log: this.log, item, isMatching });
++    return isMatching;
+   }
+ }
+
+ export class MatchAttributes implements ItemFilter {
+   private readonly attributes: Partial<MatchableItem>;
++  private log: Logger;
+
+-  constructor(attributes: Partial<MatchableItem>) {
++  constructor(attributes: Partial<MatchableItem>, log: Logger) {
+     this.attributes = attributes;
++    this.log = log.child({ class: 'MatchAttributes' });
+   }
+
+   async match(item: MatchableItem): Promise<boolean> {
+@@ -145,21 +203,27 @@ export class MatchAttributes implements ItemFilter {
+       }
+     }
+
+-    if (matches.size === Object.keys(this.attributes).length) {
+-      return true;
+-    }
+-
+-    return false;
++    const isMatching = matches.size === Object.keys(this.attributes).length;
++    logMatchResult({ log: this.log, item, isMatching });
++    return isMatching;
+   }
+ }
+
+ export class MatchNestedBundle implements ItemFilter {
++  private log: Logger;
++
++  constructor(log: Logger) {
++    this.log = log.child({ class: 'MatchNestedBundle' });
++  }
++
+   async match(item: MatchableItem): Promise<boolean> {
+     const hasParentId =
+       item.parent_id !== undefined &&
+       item.parent_id !== null &&
+       item.parent_id !== '';
+
++    const isMatching = hasParentId;
++    logMatchResult({ log: this.log, item, isMatching });
+     return hasParentId;
+   }
+ }
+@@ -191,27 +255,60 @@ export class MatchNestedBundle implements ItemFilter {
+  *
+  *   { never: true }
+  */
+-export function createFilter(filter: any): ItemFilter {
++export function createFilter(filter: any, logger: Logger): ItemFilter {
++  const log = logger.child({ class: 'ItemFilter' });
++
+   if (filter === undefined || filter === '') {
+-    return new NeverMatch();
++    return new NeverMatch(log);
+   }
+
+   if (filter?.tags) {
+-    return new MatchTags(filter.tags);
++    return new MatchTags(
++      filter.tags,
++      log.child({ itemFilter: JSON.stringify({ tags: filter.tags }) }),
++    );
+   } else if (filter?.attributes) {
+-    return new MatchAttributes(filter.attributes);
++    return new MatchAttributes(
++      filter.attributes,
++      log.child({
++        itemFilter: JSON.stringify({ attributes: filter.attributes }),
++      }),
++    );
+   } else if (filter?.isNestedBundle) {
+-    return new MatchNestedBundle();
++    return new MatchNestedBundle(
++      log.child({
++        itemFilter: JSON.stringify({ isNestedBundle: filter.isNestedBundle }),
++      }),
++    );
+   } else if (filter?.not) {
+-    return new NegateMatch(createFilter(filter.not));
++    const childLogger = log.child({
++      itemFilter: JSON.stringify({ not: filter.not }),
++    });
++    return new NegateMatch(createFilter(filter.not, childLogger), childLogger);
+   } else if (filter?.and) {
+-    return new MatchAll(filter.and.map(createFilter));
++    const childLogger = log.child({
++      itemFilter: JSON.stringify({ and: filter.and }),
++    });
++    return new MatchAll(
++      filter.and.map((and: any) => createFilter(and, childLogger)),
++      childLogger,
++    );
+   } else if (filter?.or) {
+-    return new MatchAny(filter.or.map(createFilter));
++    const childLogger = log.child({
++      itemFilter: JSON.stringify({ or: filter.or }),
++    });
++    return new MatchAny(
++      filter.or.map((or: any) => createFilter(or, childLogger)),
++      childLogger,
++    );
+   } else if (filter?.never) {
+-    return new NeverMatch();
++    return new NeverMatch(
++      log.child({ itemFilter: JSON.stringify({ never: filter.never }) }),
++    );
+   } else if (filter?.always) {
+-    return new AlwaysMatch();
++    return new AlwaysMatch(
++      log.child({ itemFilter: JSON.stringify({ always: filter.always }) }),
++    );
+   }
+
+   throw new Error(`Invalid filter: ${filter}`);
+diff --git a/src/log.ts b/src/log.ts
+index 639e874..f6f8a57 100644
+--- a/src/log.ts
++++ b/src/log.ts
+@@ -25,6 +25,25 @@ const LOG_ALL_STACKTRACES =
+ const LOG_FORMAT = env.varOrDefault('LOG_FORMAT', 'simple');
+ const INSTANCE_ID = env.varOrUndefined('INSTANCE_ID');
+
++type ItemFilterChildLoggerOpts = {
++  itemFilter: string;
++};
++
++// in the filters.ts file, we want to build a tree of filters
++// so we concatinate previous filter string to the next one
++const appendItemFilterFormat = format((info, opts: unknown) => {
++  if (
++    typeof opts === 'object' &&
++    typeof (opts as ItemFilterChildLoggerOpts).itemFilter === 'string'
++  ) {
++    const optsFromChildLogger = opts as ItemFilterChildLoggerOpts;
++    info.itemFilter = info.itemFilter
++      ? `${info.filter} AND ${optsFromChildLogger.itemFilter}`
++      : optsFromChildLogger.itemFilter;
++  }
++  return info;
++});
++
+ const logger = createLogger({
+   level: LOG_LEVEL,
+   defaultMeta: {
+@@ -42,6 +61,7 @@ const logger = createLogger({
+     format.errors(),
+     format.timestamp(),
+     LOG_FORMAT === 'json' ? format.json() : format.simple(),
++    appendItemFilterFormat(),
+   ),
+   transports: new transports.Console(),
+ });
+diff --git a/src/workers/ans104-data-indexer.ts b/src/workers/ans104-data-indexer.ts
+index 2e72dc6..7f91dd9 100644
+--- a/src/workers/ans104-data-indexer.ts
++++ b/src/workers/ans104-data-indexer.ts
+@@ -32,6 +32,7 @@ const DEFAULT_WORKER_COUNT = 1;
+
+ export class Ans104DataIndexer {
+   // Dependencies
++
+   private log: winston.Logger;
+   private eventEmitter: EventEmitter;
+   private indexWriter: NestedDataIndexWriter;

src/config.ts

@@ -22,6 +22,7 @@ import { existsSync, readFileSync } from 'node:fs';
 import { createFilter } from './filters.js';
 import * as env from './lib/env.js';
 import { release } from './version.js';
+import logger from './log.js';
 
 //
 // HTTP server
@@ -202,6 +203,7 @@ export const ANS104_UNBUNDLE_FILTER_STRING = canonicalize(
 );
 export const ANS104_UNBUNDLE_FILTER = createFilter(
   JSON.parse(ANS104_UNBUNDLE_FILTER_STRING),
+  logger,
 );
 
 // Filter determining which ANS-104 data items to index
@@ -213,6 +215,7 @@ export const ANS104_INDEX_FILTER_STRING = canonicalize(
 );
 export const ANS104_INDEX_FILTER = createFilter(
   JSON.parse(ANS104_INDEX_FILTER_STRING),
+  logger,
 );
 
 // The number of ANS-104 worker threads to run
@@ -449,6 +452,7 @@ export const WEBHOOK_INDEX_FILTER_STRING = canonicalize(
 );
 export const WEBHOOK_INDEX_FILTER = createFilter(
   JSON.parse(WEBHOOK_INDEX_FILTER_STRING),
+  logger,
 );
 
 // Block filter to use for webhooks
@@ -457,6 +461,7 @@ export const WEBHOOK_BLOCK_FILTER_STRING = canonicalize(
 );
 export const WEBHOOK_BLOCK_FILTER = createFilter(
   JSON.parse(WEBHOOK_BLOCK_FILTER_STRING),
+  logger,
 );
 
 //