fix(objectql): name which case the per-option visibleWhen fail-open log took (#14485)

A system write can never bind `current_user`, so every gated option a seed
carries took the fail-open branch and logged `failed to evaluate — allowed
through` — 27 identical lines on one ordinary boot, on the correct path. An
authenticated caller whose predicate genuinely faults produced the identical
line, and that one is a gate that is not being enforced.

The admission is unchanged. The branch now says which of the two cases it
took, in the message and in structured `meta.reason`, and both stay at `warn`
(the published sink declares no other level, and the authenticated fault must
not get quieter). The discriminator needs both facts — no acting user AND a
predicate that references one — and reads the second off the parsed CEL AST
rather than off the fault text, which was measured not to be a reliable key.


Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68

Co-authored-by: Claude <noreply@anthropic.com>

Author: os-musk

.changeset/option-visibility-system-write-log.md

@@ -0,0 +1,65 @@
+---
+"@objectstack/objectql": patch
+---
+
+fix(objectql): the per-option `visibleWhen` fail-open log now names which of its two cases it took (#14416)
+
+`evaluateOptionVisibility` admits an option whose `visibleWhen` predicate cannot
+be evaluated, and logs it. **That admission is unchanged and deliberate** — a
+seed that could not write a gated value would have to walk every row through the
+state machine, and a job with no acting user could not write at all. Only the
+log changes.
+
+One sentence was describing two different facts. A system write (a declarative
+seed, an in-process job — anything with no acting user) can never bind
+`current_user`, so every gated option it carries took the fail-open branch and
+logged `option visibleWhen for '<f>=<v>' failed to evaluate — allowed through`:
+measured at 27 identical lines on one ordinary boot of a seeded app, one per
+seeded row, on the correct path. An authenticated caller whose predicate
+genuinely faults — a typo'd field, a missing root — produced the **identical**
+line, and that one is a gate that is not being enforced. A warning that fires
+this often on the expected path stops being read, and takes the real case with
+it.
+
+The branch now states which case it is:
+
+- **No acting user, and the predicate asks for one** — reworded to
+  `option visibleWhen for '<f>=<v>' not evaluated: no acting user to bind
+  current_user (system write) — allowed through`. It deliberately no longer
+  contains the phrase `failed to evaluate`, so an operator grepping a boot log
+  for that phrase stops matching the expected path.
+- **Everything else** — kept loud and now says the gate was not enforced and
+  needs checking, with the caller named (`authenticated caller` / `system
+  write`).
+
+**Log level is unchanged: both branches stay at `warn`.** The authenticated
+fault must not get quieter, and the published sink type
+(`EvaluateRulesOptions['logger']`) keeps its shape — it declares `warn` only,
+and this change does not widen it. Demoting the no-acting-user case to `debug`
+would require adding a `debug` member to that published type and is
+deliberately **not** done here.
+
+Both calls now also pass structured `meta` through the sink's already-declared
+`(msg, meta?)` second parameter — **additive, no type change**:
+
+- `field` — the field name
+- `value` — the picked option value, stringified
+- `reason` — `'no-acting-user'` or `'predicate-fault'`, the machine-readable
+  form of the distinction above
+- `error` — the engine's `EvalError` (`{ kind, message }`), so the underlying
+  fault stays recoverable from the line even when the line is the quiet one
+
+The discriminator needs **both** facts — no acting user **and** a predicate that
+references the acting user — and reads the second off the parsed CEL AST
+(`collectCelRootIdentifiers`, the reader this file already uses for the `parent`
+root), never off the fault's message text. Measured: with no acting user,
+`'admin' in current_user.positions` reports `Unknown variable: current_user`,
+but `'admin' in current_user.positions && record.typo == 1` reports `No such
+key: typo` — a message-matching key would file that second predicate as a live
+gate failure on every system write. `current_user`'s ADR-0068 aliases (`user`,
+`ctx.user`, `os.user`) count as the same root, since `buildScope` mounts one
+`EvalUser` under all four and none of them without a user.
+
+No behaviour change: the accept/reject set does not move, a clean `false` is
+still refused with `invalid_option`, and an unevaluable predicate is still
+allowed through.

packages/objectql/src/validation/rule-validator.option-visibility.test.ts

@@ -102,6 +102,189 @@ describe('per-option visibleWhen — role gating', () => {
   });
 });
 
+/**
+ * #14416 — the fail-open branch must say WHICH of its two cases it took.
+ *
+ * A system write (a declarative seed, an in-process job) can never bind
+ * `current_user`, so a role-gated option logged one `failed to evaluate —
+ * allowed through` per seeded row — 27 on one ordinary boot, on the correct
+ * path. An authenticated caller whose predicate genuinely faults produced the
+ * identical line, and that one is a gate that is not being enforced.
+ *
+ * Both branches stay at `warn` (the sink declares only `warn`, and the
+ * authenticated fault must not get quieter). What the pins hold is that the two
+ * are told apart, that the fail-open ADMISSION is unchanged in both, and that
+ * the discriminator needs BOTH facts — no acting user AND a predicate that asks
+ * for one. A test that only checked the new wording would pass with the branch
+ * still absent, so every case below asserts `meta.reason` too.
+ */
+describe('per-option visibleWhen — fail-open diagnostics name their case (#14416)', () => {
+  /** Collect `(msg, meta)` pairs off the declared `{ warn? }` sink. */
+  function capture() {
+    const warns: Array<{ msg: string; meta: any }> = [];
+    return { warns, logger: { warn: (msg: string, meta?: any) => warns.push({ msg, meta }) } };
+  }
+
+  // A predicate that names no user root at all and faults on a typo'd field:
+  // the case the "no acting user" discriminator MUST NOT swallow.
+  const typoSchema = {
+    fields: {
+      grade: {
+        type: 'select',
+        options: [{ value: 'gold', visibleWhen: 'record.typo_field == 1' }],
+      },
+    },
+  };
+
+  it('system write + a current_user predicate ⇒ one qualified warn, reason no-acting-user, value admitted', () => {
+    const { warns, logger } = capture();
+    expect(() =>
+      evaluateValidationRules(schema, { tier: 'admin_only' }, 'insert', { logger }),
+    ).not.toThrow(); // fail-open admission unchanged — the seed writes the gated value
+
+    expect(warns).toHaveLength(1);
+    expect(warns[0].msg).toBe(
+      "option visibleWhen for 'tier=admin_only' not evaluated: no acting user to bind current_user (system write) — allowed through",
+    );
+    // The old line said "failed to evaluate", which is what an operator escalates.
+    expect(warns[0].msg).not.toContain('failed to evaluate');
+    expect(warns[0].meta).toMatchObject({
+      field: 'tier',
+      value: 'admin_only',
+      reason: 'no-acting-user',
+    });
+    // The underlying fault stays recoverable from the line, not just its label.
+    expect(warns[0].meta.error).toMatchObject({ kind: expect.any(String) });
+  });
+
+  it('authenticated caller + a genuinely faulting predicate ⇒ the loud warn, reason predicate-fault, value admitted', () => {
+    const { warns, logger } = capture();
+    expect(() =>
+      evaluateValidationRules(typoSchema, { grade: 'gold' }, 'insert', {
+        currentUser: { id: 'u1', positions: ['admin'] },
+        logger,
+      }),
+    ).not.toThrow(); // still fail-open — this card changes the log, not the admission
+
+    expect(warns).toHaveLength(1);
+    expect(warns[0].msg).toContain("option visibleWhen for 'grade=gold' failed to evaluate");
+    expect(warns[0].msg).toContain('(authenticated caller)');
+    expect(warns[0].msg).toContain('the option\'s gate was NOT enforced on this write');
+    expect(warns[0].meta).toMatchObject({
+      field: 'grade',
+      value: 'gold',
+      reason: 'predicate-fault',
+    });
+  });
+
+  it('system write + a predicate naming NO user root ⇒ still the LOUD line (the case the user-less test alone would misfile)', () => {
+    // This is why the discriminator is not `currentUser === undefined` on its
+    // own: nothing about this write is expected — the predicate is broken and
+    // its gate is not being enforced, acting user or not.
+    const { warns, logger } = capture();
+    expect(() => evaluateValidationRules(typoSchema, { grade: 'gold' }, 'insert', { logger })).not.toThrow();
+
+    expect(warns).toHaveLength(1);
+    expect(warns[0].msg).toContain('failed to evaluate');
+    expect(warns[0].msg).toContain('(system write)');
+    expect(warns[0].msg).toContain('Check the predicate.');
+    expect(warns[0].meta).toMatchObject({ reason: 'predicate-fault' });
+  });
+
+  it('reads the user root off the AST, not off the fault text (a second fault must not re-loud a seed line)', () => {
+    // Measured on this tree: with no acting user,
+    //   `'admin' in current_user.positions`                    → Unknown variable: current_user
+    //   `'admin' in current_user.positions && record.typo == 1` → No such key: typo
+    // so a key that matched the message would file the second one as a live
+    // gate failure on every system write — the noise this branch removes.
+    const both = {
+      fields: {
+        tier: {
+          type: 'select',
+          options: [
+            { value: 'admin_only', visibleWhen: "'admin' in current_user.positions && record.typo == 1" },
+          ],
+        },
+      },
+    };
+    const { warns, logger } = capture();
+    expect(() => evaluateValidationRules(both, { tier: 'admin_only' }, 'insert', { logger })).not.toThrow();
+
+    expect(warns).toHaveLength(1);
+    expect(warns[0].meta).toMatchObject({ reason: 'no-acting-user' });
+    expect(warns[0].meta.error.message).toContain('No such key: typo'); // the other fault, still reported
+  });
+
+  it('a user-root ALIAS on a system write is the same case (buildScope mounts one object under four roots)', () => {
+    // ADR-0068 D1: `current_user` is canonical, `user` / `ctx.user` / `os.user`
+    // are aliases for the SAME EvalUser — none of them bind without a user, so
+    // an alias-spelled gate must not be the loud line on a seed either.
+    for (const source of ['user.id == record.owner', 'ctx.user.id == record.owner', 'os.user.id == record.owner']) {
+      const aliased = {
+        fields: { flag: { type: 'select', options: [{ value: 'on', visibleWhen: source }] } },
+      };
+      const { warns, logger } = capture();
+      expect(() => evaluateValidationRules(aliased, { flag: 'on' }, 'insert', { logger })).not.toThrow();
+      expect(warns, source).toHaveLength(1);
+      expect(warns[0].meta, source).toMatchObject({ reason: 'no-acting-user' });
+    }
+  });
+
+  describe('regression controls — the accept/reject set does not move', () => {
+    it('authenticated caller + predicate FALSE ⇒ still refused with invalid_option', () => {
+      const { warns, logger } = capture();
+      let caught: any;
+      try {
+        evaluateValidationRules(schema, { tier: 'admin_only' }, 'insert', {
+          currentUser: { id: 'u1', positions: ['sales'] },
+          logger,
+        });
+      } catch (err) {
+        caught = err;
+      }
+      expect(caught).toBeInstanceOf(ValidationError);
+      expect(caught.code).toBe('VALIDATION_FAILED');
+      expect(caught.fields).toEqual([
+        expect.objectContaining({ field: 'tier', code: 'invalid_option' }),
+      ]);
+      expect(warns).toHaveLength(0); // a clean FALSE is a decision, not a diagnostic
+    });
+
+    it('authenticated caller + predicate TRUE ⇒ admitted, no warn', () => {
+      const { warns, logger } = capture();
+      expect(() =>
+        evaluateValidationRules(schema, { tier: 'admin_only' }, 'insert', {
+          currentUser: { id: 'u1', positions: ['admin'] },
+          logger,
+        }),
+      ).not.toThrow();
+      expect(warns).toHaveLength(0);
+    });
+
+    it('a cascade predicate that evaluates cleanly on a system write still rejects', () => {
+      // No user root, nothing unbound — the gate is enforced on system writes too.
+      const { warns, logger } = capture();
+      expect(() =>
+        evaluateValidationRules(schema, { country: 'us', province: 'zj' }, 'insert', { logger }),
+      ).toThrow(ValidationError);
+      expect(warns).toHaveLength(0);
+    });
+  });
+
+  it('reproduces the card: N seeded rows log N lines, and none of them says "failed to evaluate"', () => {
+    // The card measured 27 identical `failed to evaluate — allowed through`
+    // lines on one boot, one per seeded row carrying a gated option value.
+    const N = 27;
+    const { warns, logger } = capture();
+    for (let i = 0; i < N; i++) {
+      evaluateValidationRules(schema, { tier: 'admin_only' }, 'insert', { logger });
+    }
+    expect(warns).toHaveLength(N); // the record of each admission is kept (option (c), not (a))
+    expect(warns.filter((w) => w.msg.includes('failed to evaluate'))).toHaveLength(0);
+    expect(warns.filter((w) => w.meta?.reason === 'no-acting-user')).toHaveLength(N);
+  });
+});
+
 describe('per-option visibleWhen — multi-select element-wise', () => {
   const multi = {
     fields: {

packages/objectql/src/validation/rule-validator.ts

@@ -1763,6 +1763,58 @@ function toExpression(cond: string | Expression): Expression {
   return typeof cond === 'string' ? { dialect: 'cel', source: cond } : cond;
 }
 
+/**
+ * The CEL scope roots the acting user is mounted under, so a predicate that
+ * NEEDS a user can be told apart from one that does not.
+ *
+ * ADR-0068 D1's canonical root is `current_user`; `@objectstack/formula`'s
+ * `buildScope` mounts the SAME `EvalUser` object under `user`, `ctx.user` and
+ * `os.user` as aliases, and mounts none of them when the evaluation carries no
+ * user. `ctx` and `os` are listed at bare-root granularity because that is what
+ * {@link collectCelRootIdentifiers} reports — and that is exact at THIS call
+ * site rather than merely conservative: {@link evaluateOptionVisibility}
+ * evaluates with `{ record, previous, user }` and nothing else, so `buildScope`
+ * has no `org`/`env` to mount `os` from and no other source for `ctx`. Both
+ * roots are therefore bound here if and only if a user is.
+ */
+const USER_SCOPE_ROOTS: readonly string[] = ['current_user', 'user', 'ctx', 'os'];
+
+/** Parsed-root memo — the twin of {@link parentRootCache}, same fixed sources. */
+const userRootCache = new Map<string, boolean>();
+
+/**
+ * Does this predicate reference the acting user under any root
+ * {@link USER_SCOPE_ROOTS} names?
+ *
+ * Read off the parsed CEL AST ({@link collectCelRootIdentifiers}), the same
+ * reader {@link readsParentRoot} uses — **never** off the evaluation fault's
+ * text, which was measured on this tree to be an unreliable key for the same
+ * question: with no acting user, `'admin' in current_user.positions` reports
+ * `Unknown variable: current_user`, but `'admin' in current_user.positions &&
+ * record.typo == 1` reports `No such key: typo` instead. A message-matching key
+ * would file that second predicate as a live gate failure on every system
+ * write — the exact noise this branch exists to end.
+ *
+ * A non-CEL dialect, an AST-only expression, or source that does not parse
+ * answers `false`, i.e. the loud branch. That is the safe direction and it is
+ * not a lost case: `celEngine.evaluate` itself refuses an expression with no
+ * `source` (`AST-only evaluation not yet supported; persist \`source\``), so
+ * anything this reader cannot see is a predicate the evaluator could not have
+ * run either, on any write, and it should be said loudly.
+ */
+function readsUserRoot(cond: string | Expression): boolean {
+  const expr = toExpression(cond);
+  if (expr.dialect !== 'cel') return false;
+  const source = typeof expr.source === 'string' ? expr.source : '';
+  if (!source) return false;
+  const cached = userRootCache.get(source);
+  if (cached !== undefined) return cached;
+  const roots = collectCelRootIdentifiers(source);
+  const answer = roots.ok && roots.roots.some((r) => USER_SCOPE_ROOTS.includes(r));
+  userRootCache.set(source, answer);
+  return answer;
+}
+
 /**
  * Per-option authorization / cascade enforcement (objectui#2284).
  *
@@ -1781,6 +1833,20 @@ function toExpression(cond: string | Expression): Expression {
  * every other field rule here: a broken cascade predicate must never brick a
  * write. Authorization gating therefore depends on the engine binding
  * `current_user` on authenticated writes.
+ *
+ * The admission is deliberate and unchanged. What the fail-open branch does NOT
+ * do any more is describe two different facts with one sentence. A system write
+ * — a declarative seed, an in-process job, anything with no acting user — can
+ * never bind `current_user`, so every gated option it carries took that branch
+ * and logged `failed to evaluate — allowed through`: measured at 27 identical
+ * lines on one ordinary boot of a seeded app, one per seeded row, on the
+ * correct path. An authenticated caller whose predicate genuinely faults (a
+ * typo'd field, a missing root) produced the *identical* line, and that one is
+ * a gate that is not being enforced. A signal that fires this often on the
+ * expected path stops being read, and takes the real case with it. The branch
+ * below states which of the two happened, in the message and in structured
+ * `meta.reason`; both stay at `warn` — the authenticated fault must not get
+ * quieter, and the sink offers no other level.
  */
 function evaluateOptionVisibility(
   fields: Record<string, ConditionalFieldDef> | undefined,
@@ -1813,9 +1879,25 @@ function evaluateOptionVisibility(
         user,
       });
       if (!res.ok) {
-        logger?.warn?.(
-          `option visibleWhen for '${name}=${String(value)}' failed to evaluate — allowed through`,
-        );
+        // Which of the two fail-open cases is this? "No acting user to bind"
+        // needs BOTH facts — the write carries no user AND the predicate asks
+        // for one. Either alone misfiles: a system write whose predicate names
+        // no user root and faults on a typo'd field is a real broken gate, and
+        // an authenticated caller's fault is the case this log exists for.
+        const noActingUser = user === undefined;
+        if (noActingUser && readsUserRoot(opt.visibleWhen)) {
+          logger?.warn?.(
+            `option visibleWhen for '${name}=${String(value)}' not evaluated: no acting user to bind current_user (system write) — allowed through`,
+            { field: name, value: String(value), reason: 'no-acting-user', error: res.error },
+          );
+        } else {
+          logger?.warn?.(
+            `option visibleWhen for '${name}=${String(value)}' failed to evaluate `
+              + `(${noActingUser ? 'system write' : 'authenticated caller'}) — allowed through; `
+              + `the option's gate was NOT enforced on this write. Check the predicate.`,
+            { field: name, value: String(value), reason: 'predicate-fault', error: res.error },
+          );
+        }
         continue; // fail-open
       }
       if (res.value === false) {