Skip to content

emerging_signals reports dated log lines as both "new" and "gone": Drain keeps the literal date, and each window is mined separately #3544

Open

Description

@bcanvural

Summary

On logs that carry a date in the message (most Java/Log4j/Logback lines, batch jobs with run ids), clickstack_emerging_signals against a yesterday baseline returns mostly false positives: the same pattern appears once as emerging and once as disappeared, because the two templates differ only by the date.

Three things combine:

  1. No masking before Drain. minePatterns uses a default TemplateMinerConfig (packages/common-utils/src/drain/mine-patterns.ts:110) with no masking instructions (drain/config.ts:14). Numeric tokens only go to <*> during tree descent; within one window every line has the same date, so the date stays literal in the template (2026-11-04 <*> ERROR …).
  2. Two separate Drain trees. The baseline and current windows are mined independently (emergingSignals.ts:206) and matched by template text (normalizeTemplate, L239). Even on the same day, a token that happened to be constant in one window stays literal there and becomes <*> in the other, so the keys differ.
  3. bodyExpression must be a bare column (runEventPatterns.ts:88-104), so users can't work around it with replaceRegexpOne(Body, '^\\S+ ', ''), a substring, or a JSON field such as JSONExtractString(Body, 'event'). clickstack_table and clickstack_search already accept expressions.

Environment

HyperDX 2-nightly image (late Oct 2026) with ClickHouse 26.10.3. Code references checked on main at d08b2fa (2026-11-03, 2.43.1).

Steps to reproduce

Self-contained, using the real TemplateMiner from main (repro.mts below): 200 lines per day of the form

2026-11-03 06:12:12.345 ERROR [worker-3] c.e.SyncJob - Sync failed for account 1003: HTTP 500

mined for 2026-11-03 (baseline) and 2026-11-04 (current), keyed the way emerging_signals keys them:

no masking:              emerging=2, disappeared=2   (e.g. "2026-11-04 <*> error <*> … http 500")
with a timestamp mask:   emerging=0, disappeared=0
same day, separate trees: emerging=1, disappeared=1  ("… host=db-1 …" vs "… <*> …")

On real data: emerging_signals with a yesterday baseline on 4 services returned 34/54, 109/135, 52/100 and 19/42 emerging/disappeared patterns, almost all of them the same lines with a different date (or run_id=scheduled__2026-11-04T06:00…). A same-day baseline still gave 22/56.

Expected vs actual

Lines that differ only by timestamp, UUID or run id should be one pattern in both windows, so they are neither emerging nor disappeared. Today they are reported as both.

Impact

The tool's own description says to use it for status checks and post-deploy diffs, and that "an empty emerging list is a valid answer". On dated logs the list is never empty, so agents either report false findings or learn to distrust the tool.

Proposed fix

  1. Default masking instructions in minePatterns for ISO-8601 and RFC-1123 timestamps, UUIDs and long hex ids (the TemplateMinerConfig.maskingInstructions hook already exists).
  2. Mine both windows with one TemplateMiner (feed the baseline sample, then the current one, tagging rows by window) and compare by cluster id instead of template text.
  3. Let bodyExpression be any expression the SQL validator accepts, as the table and search tools already do, so users can strip a prefix or mine a JSON field.

Related

repro.mts
// Repro: emerging_signals keys Drain templates by text, and dated log lines keep
// the literal date in the template, so the same pattern is "emerging" AND "disappeared".
// Run: npx tsx repro.mts <hyperdx-checkout>/packages/common-utils/src/drain
import { pathToFileURL } from 'node:url';

const drainDir = process.argv[2];
const { TemplateMiner } = await import(pathToFileURL(`${drainDir}/template-miner.ts`).href);
const { TemplateMinerConfig } = await import(pathToFileURL(`${drainDir}/config.ts`).href);

// Same as normalizeTemplate() in packages/api/src/mcp/tools/query/runEventPatterns.ts
const normalizeTemplate = (p: string) =>
  p.replace(/<\*>/g, '\u0001').replace(/\s+/g, ' ').trim().toLowerCase();

const lines = (day: string) =>
  Array.from({ length: 200 }, (_, i) => [
    `${day} 06:${String(i % 60).padStart(2, '0')}:12.345 ERROR [worker-${i % 7}] c.e.SyncJob - Sync failed for account ${1000 + i}: HTTP 500`,
    `${day} 06:${String(i % 60).padStart(2, '0')}:13.001 INFO  [worker-${i % 7}] c.e.SyncJob - Sync finished in ${i * 3} ms`,
  ]).flat();

function mine(rows: string[], masking: { pattern: string; maskWith: string }[]) {
  const config = new TemplateMinerConfig(); // what minePatterns() uses today: no masking instructions
  config.maskingInstructions = masking;
  const miner = new TemplateMiner(config);
  const templates = new Map<number, string>();
  for (const r of rows) {
    const res = miner.addLogMessage(r);
    templates.set(res.clusterId, res.templateMined);
  }
  return new Set([...templates.values()].map(normalizeTemplate));
}

for (const [label, masking] of [
  ['today (no masking)', []],
  ['with a date/time mask', [{ pattern: '\\d{4}-\\d{2}-\\d{2}[ T]\\d{2}:\\d{2}:\\d{2}(\\.\\d+)?', maskWith: 'TS' }]],
] as const) {
  const baseline = mine(lines('2026-11-03'), [...masking]);
  const current = mine(lines('2026-11-04'), [...masking]);
  const emerging = [...current].filter(t => !baseline.has(t));
  const gone = [...baseline].filter(t => !current.has(t));
  console.log(`${label}: ${current.size} templates; emerging=${emerging.length}, disappeared=${gone.length}`);
  for (const t of emerging) console.log('  emerging:', t.replace(/\u0001/g, '<*>'));
}

// Same day, no dates involved: each window is mined by its own Drain tree, so a token
// that happened to be constant in one window stays literal there and becomes <*> in the other.
const sameDay = (hosts: string[]) => Array.from({ length: 200 }, (_, i) =>
  `upstream connect error host=${hosts[i % hosts.length]} retry=${i % 3} reason=timeout`);
{
  const baseline = mine(sameDay(['db-1']), []);
  const current = mine(sameDay(['db-1', 'db-2', 'db-3']), []);
  const emerging = [...current].filter(t => !baseline.has(t));
  const gone = [...baseline].filter(t => !current.has(t));
  console.log(`same day, separate trees: emerging=${emerging.length}, disappeared=${gone.length}`);
  for (const t of [...emerging.map(e => 'emerging: ' + e), ...gone.map(g => 'gone:     ' + g)]) console.log('  ' + t.replace(/\u0001/g, '<*>'));
}

Activity

  1. brandon-pereira commented on Nov 4, 2026

    @brandon-pereira
    Member

    Thanks for the issue.

    Agreed on #1 and #2, those are relatively small easy wins that should improve things. Open to contribution on these.

    As for #3- lets please make a new issue after #3426 ships as it will improve bodyExpression. It won't cover all scenarios, but at least we can have an issue focused on that argument specifically and keep the PRs smaller.

  2. bcanvural commented on Nov 4, 2026

    @bcanvural
    ContributorAuthor

    Update: option 1 (masking) is #3551. Option 2 (one tree) turned out to need new-variant detection, so it has its own issue, #3556, with Draft PR #3557 stacked on #3551. Option 3 (bodyExpression) stays for a new issue after #3426 ships, as discussed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions