diff --git a/.changeset/24782-advisory-unevaluable-log.md b/.changeset/24782-advisory-unevaluable-log.md new file mode 100644 index 00000000000..269b0267054 --- /dev/null +++ b/.changeset/24782-advisory-unevaluable-log.md @@ -0,0 +1,13 @@ +--- +'@objectstack/objectql': patch +--- + +fix(objectql): an advisory validation rule that cannot be evaluated logs one line saying the write proceeded, not two saying it was rejected (#24782) + +Clause-②: no (log text only: no response, status, code, outcome or export moves) + +A `severity: 'warning'` or `'info'` validation rule whose predicate cannot be evaluated never blocks the write. Only `error` rules fail closed (#4649). The write answers 2xx and the row persists. The server log said the opposite, twice. The predicate evaluator logged "— write rejected: a rule that cannot be evaluated fails closed, it is never skipped" before the rule's severity was consulted. Then the advisory per-write line repeated the unevaluable violation's own message, which also ends "— write rejected.". + +Such a rule now logs ONE line: `Validation rule 'NAME' (warning): the rule could not be evaluated (FAULT) — write proceeded: the rule is advisory, so it was not applied to this write`. This covers a `script` / `cross_field` condition, a `conditional`'s `when`, and the relationship-traversal refusal. On the seed / boot path the same text folds into that load's advisory summary line, which keeps its shape. + +Unchanged: an unevaluable `error` rule is refused with the same `400 VALIDATION_FAILED` body, and its log line still says the write was rejected and the rule fails closed. Which rules block is unchanged. An unevaluable rule still stays out of a write answer's `warnings`. `requiredWhen`, `readonlyWhen` and the option `visibleWhen` gate still refuse on every severity. diff --git a/packages/objectql/src/validation/advisory-write-answer.test.ts b/packages/objectql/src/validation/advisory-write-answer.test.ts index d3a666a716b..d90ab5279f3 100644 --- a/packages/objectql/src/validation/advisory-write-answer.test.ts +++ b/packages/objectql/src/validation/advisory-write-answer.test.ts @@ -482,3 +482,33 @@ describe('[#22726] P2 — the preview appends the same hits to the row\'s `warni ]); }); }); + +describe('[#24782] an unevaluable advisory rule: the write succeeds, and the log says so once', () => { + beforeEach(async () => { + await boot(); + engine.registry.registerObject({ + name: 'adv_unevaluable', + label: 'Probe', + fields: { title: { name: 'title', label: 'Title', type: 'text' } }, + validations: [{ + type: 'script' as const, + name: 'qa_unevaluable_warn', + severity: 'warning' as const, + message: 'x', + condition: 'int(record.title) > 1', + }], + } as never, 'com.objectstack.test.24782'); + }); + + it('createData stores the row, answers no `warnings`, and logs one advisory line', async () => { + const res: any = await protocol.createData({ object: 'adv_unevaluable', data: { title: 'abc' } }); + + expect(storeFor('adv_unevaluable').get(res.id)).toMatchObject({ title: 'abc' }); + // #22726: an unevaluable rule has no verdict, so it is not a hit. + expect(Object.keys(res)).not.toContain('warnings'); + const ruleLines = warns.filter((l) => l.includes('qa_unevaluable_warn')); + expect(ruleLines).toHaveLength(1); + expect(ruleLines[0]).toMatch(/^Validation rule 'qa_unevaluable_warn' \(warning\): the rule could not be evaluated \(.+\) — write proceeded/); + expect(ruleLines[0]).not.toMatch(/write rejected|fails closed/); + }); +}); diff --git a/packages/objectql/src/validation/rule-unevaluable-advisory-log.test.ts b/packages/objectql/src/validation/rule-unevaluable-advisory-log.test.ts new file mode 100644 index 00000000000..b4012674441 --- /dev/null +++ b/packages/objectql/src/validation/rule-unevaluable-advisory-log.test.ts @@ -0,0 +1,194 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +import { describe, it, expect } from 'vitest'; +import { runWithAdvisoryAggregation, type AdvisoryGroup } from '@objectstack/core'; + +import { evaluateValidationRules } from './rule-validator.js'; +import { ValidationError } from './record-validator.js'; + +// [#10126] Pay the first transform of these dist-resolved workspace deps at MODULE +// LOAD, not inside a clocked `it()` body. +import '@objectstack/spec'; +import '@objectstack/formula'; + +/** + * [#24782] What the operator log says about a validation rule that could not be + * EVALUATED, by severity. + * + * #4649 fails such a rule closed — but `severity` still governs blocking, so an + * unevaluable `warning` / `info` rule never refuses the write. Until #24782 its + * log said the opposite, twice: the predicate evaluator's fail-closed sentence + * ("— write rejected: a rule that cannot be evaluated fails closed"), logged + * before the rule's severity was consulted, and the advisory branch's per-write + * line, which embedded the unevaluable violation's own message (ending + * "— write rejected."). An operator reading the log for a disputed write was + * told it was refused when it was stored. + * + * The pins: + * - an unevaluable advisory rule logs exactly ONE line, naming the rule, its + * severity and the fault, and saying the write proceeded — never "write + * rejected", never "fails closed" — on each predicate slot: a `script` + * condition, a `conditional`'s `when`, and the relationship-traversal refusal; + * - the seed / boot aggregation (#13889) folds that same advisory text; + * - CONTROL: an unevaluable `error` rule is refused exactly as before, and its + * log still says the write was rejected and the rule fails closed. + */ + +const FAULTED_CONDITION = 'int(record.title) > 1'; + +const probe = (severity: 'error' | 'warning' | 'info') => ({ + name: 'qa_vr_probe', + fields: { title: { type: 'text', label: 'Title' } }, + validations: [ + { type: 'script', name: 'qa_unevaluable', severity, message: 'x', condition: FAULTED_CONDITION }, + ], +}); + +const conditionalProbe = (severity: 'error' | 'warning') => ({ + name: 'qa_vr_probe', + fields: { title: { type: 'text', label: 'Title' } }, + validations: [ + { + type: 'conditional', + name: 'qa_unevaluable_when', + severity, + message: 'x', + when: FAULTED_CONDITION, + then: { type: 'script', name: 'qa_then', message: 'then', condition: 'false' }, + }, + ], +}); + +/** A rule reading one hop through a lookup whose parent row was unreadable. */ +const traversalProbe = (severity: 'error' | 'warning') => ({ + name: 'crm_opportunity', + fields: { + amount: { type: 'currency', label: 'Amount' }, + account: { type: 'lookup', reference: 'crm_account', label: 'Account' }, + }, + validations: [ + { + type: 'script', + name: 'partner_cap', + severity, + message: 'Partner accounts are capped at 10000.', + fields: ['amount'], + condition: "record.account.type == 'partner' && record.amount > 10000", + }, + ], +}); +const unreadableAccount = { account: { object: 'crm_account', unavailable: 'unreadable' } }; + +function run( + schema: unknown, + data: Record, + related?: Record, +): { warns: string[]; thrown: unknown; returned: unknown } { + const warns: string[] = []; + let thrown: unknown; + let returned: unknown; + try { + returned = evaluateValidationRules(schema as never, data, 'insert', { + logger: { warn: (m: unknown) => { warns.push(String(m)); } }, + ...(related ? { related: related as never } : {}), + }); + } catch (err) { + thrown = err; + } + return { warns, thrown, returned }; +} + +function expectOneAdvisoryLine(warns: string[], rule: string, severity: string, fault: RegExp): void { + expect(warns).toHaveLength(1); + const [line] = warns; + expect(line).toContain(`Validation rule '${rule}' (${severity}):`); + expect(line).toMatch(fault); + expect(line).toContain('write proceeded'); + expect(line).not.toMatch(/write rejected/); + expect(line).not.toMatch(/fails closed/); +} + +describe('[#24782] an unevaluable ADVISORY rule logs one line, and it says the write proceeded', () => { + it.each(['warning', 'info'] as const)('a `script` condition at severity %s', (severity) => { + const { warns, thrown, returned } = run(probe(severity), { title: 'abc' }); + + expect(thrown).toBeUndefined(); + // #22726: an unevaluable rule has no verdict, so it is not an advisory hit. + expect(returned).toEqual([]); + expectOneAdvisoryLine(warns, 'qa_unevaluable', severity, /could not be evaluated \(.+\)/); + }); + + it('a `conditional` whose `when` cannot be evaluated', () => { + const { warns, thrown, returned } = run(conditionalProbe('warning'), { title: 'abc' }); + + expect(thrown).toBeUndefined(); + expect(returned).toEqual([]); + expectOneAdvisoryLine(warns, 'qa_unevaluable_when', 'warning', /could not be evaluated \(.+\)/); + }); + + it('the relationship-traversal refusal (the related row was unreadable)', () => { + const { warns, thrown, returned } = run( + traversalProbe('warning'), { amount: 20000, account: 'acc_1' }, unreadableAccount, + ); + + expect(thrown).toBeUndefined(); + expect(returned).toEqual([]); + expectOneAdvisoryLine(warns, 'partner_cap', 'warning', /could not be evaluated \(.+\)/); + }); + + it('on the seed / boot path the hit folds into the summary with the same advisory text, and no per-row line', async () => { + const warns: string[] = []; + let groups: AdvisoryGroup[] = []; + await runWithAdvisoryAggregation(async () => { + evaluateValidationRules(probe('warning') as never, { title: 'abc' }, 'insert', { + logger: { warn: (m: unknown) => { warns.push(String(m)); } }, + }); + }, (g) => { groups = g; }); + + expect(warns).toEqual([]); + expect(groups).toHaveLength(1); + expect(groups[0]).toMatchObject({ rule: 'qa_unevaluable', severity: 'warning', rows: 1 }); + expect(groups[0]!.message).toMatch(/could not be evaluated \(.+\) — write proceeded/); + expect(groups[0]!.message).not.toMatch(/write rejected|fails closed/); + }); +}); + +describe('[#24782] CONTROL — an unevaluable `error` rule is refused, and its log says so', () => { + const refusalOf = (thrown: unknown) => { + expect(thrown).toBeInstanceOf(ValidationError); + return (thrown as ValidationError).fields; + }; + + it('a `script` condition', () => { + const { warns, thrown } = run(probe('error'), { title: 'abc' }); + + const fields = refusalOf(thrown); + expect(fields).toHaveLength(1); + expect(fields[0]).toMatchObject({ + field: '_record', + code: 'rule_violation', + constraint: { rule: 'qa_unevaluable', reason: 'unevaluable' }, + }); + expect(fields[0]!.message).toMatch(/^Validation rule 'qa_unevaluable' could not be evaluated \(.+\) — write rejected\./); + expect(warns).toHaveLength(1); + expect(warns[0]).toMatch( + /^Validation rule 'qa_unevaluable' predicate failed to evaluate \(.+\) — write rejected: a rule that cannot be evaluated fails closed, it is never skipped$/s, + ); + }); + + it('a `conditional` whose `when` cannot be evaluated', () => { + const { warns, thrown } = run(conditionalProbe('error'), { title: 'abc' }); + + expect(refusalOf(thrown)[0]).toMatchObject({ constraint: { rule: 'qa_unevaluable_when', reason: 'unevaluable' } }); + expect(warns).toHaveLength(1); + expect(warns[0]).toMatch(/^Validation rule 'qa_unevaluable_when' when-predicate failed to evaluate \(.+\) — write rejected: a rule that cannot be evaluated fails closed/s); + }); + + it('the relationship-traversal refusal', () => { + const { warns, thrown } = run(traversalProbe('error'), { amount: 20000, account: 'acc_1' }, unreadableAccount); + + expect(refusalOf(thrown)[0]).toMatchObject({ constraint: { rule: 'partner_cap', reason: 'unevaluable' } }); + expect(warns).toHaveLength(1); + expect(warns[0]).toMatch(/^Validation rule 'partner_cap' predicate could not be evaluated \(.+\) — write rejected$/); + }); +}); diff --git a/packages/objectql/src/validation/rule-validator.ts b/packages/objectql/src/validation/rule-validator.ts index 9e8b657813a..51aa0041d03 100644 --- a/packages/objectql/src/validation/rule-validator.ts +++ b/packages/objectql/src/validation/rule-validator.ts @@ -339,6 +339,24 @@ interface RuleContext { * when it resolved none. Applied per rule — see * {@link resolveTraversalScope}. */ related: RelatedRecordBinding | undefined; + /** [#24782] The TOP-LEVEL rule being evaluated is advisory (`warning` / + * `info`) — set per rule by `evaluateValidationRules`, and inherited by a + * `conditional`'s branch, whose outer rule's severity governs. See + * {@link failClosedLogger}. */ + advisory: boolean; +} + +/** + * [#24782] The logger an unevaluable predicate writes its fail-closed sentence + * to ("— write rejected: a rule that cannot be evaluated fails closed"): the + * write's logger for an `error` rule, whose write IS rejected, and none for an + * advisory rule, whose write proceeds. The predicate evaluators run before the + * caller acts on the rule's severity, so they cannot word the outcome + * themselves; for an advisory rule `evaluateValidationRules` reports the fault + * once, worded as what happened — see {@link unevaluableAdvisoryMessage}. + */ +function failClosedLogger(ctx: Pick): EvaluateRulesOptions['logger'] { + return ctx.advisory ? undefined : ctx.logger; } /** @@ -3438,9 +3456,10 @@ export function nullPreviousReadDetail( * `onValidationAdvisory` listener (see {@link emitValidationAdvisories}) and * the validate-only preview appends it to the row's `warnings`. A rule that * could not be EVALUATED (`constraint.reason: 'unevaluable'`) is not a hit: it - * has no verdict, and its text ("could not be evaluated … write rejected") is a - * fault report for the operator, false for a write an advisory never blocks — - * so it stays in the log only. + * has no verdict, and its text ("could not be evaluated … write rejected") is + * the refusal an `error` rule returns, false for a write an advisory never + * blocks — so it is not a hit, and the log reports it once in its own words + * ({@link unevaluableAdvisoryMessage}, #24782). */ export function evaluateValidationRules( objectSchema: { validations?: unknown[]; fields?: Record } | undefined | null, @@ -3478,7 +3497,7 @@ export function evaluateValidationRules( // and update: what a predicate can read is the object's DECLARED shape, not // whatever subset of columns this driver happened to return. if (groundTruth) materializeDeclaredFields(merged, fields); - const ctx: RuleContext = { data, merged, previous, mode, logger: opts.logger, fields, messages: opts.messages, related: opts.related }; + const ctx: RuleContext = { data, merged, previous, mode, logger: opts.logger, fields, messages: opts.messages, related: opts.related, advisory: false }; const errors: FieldValidationError[] = []; // [#22726] The advisory hits this evaluation returns — see the doc above. @@ -3603,9 +3622,10 @@ export function evaluateValidationRules( .sort((a, b) => (a.priority ?? 100) - (b.priority ?? 100)); for (const rule of ordered) { + const severity = rule.severity ?? 'error'; let violation: FieldValidationError | null = null; try { - violation = evaluateRule(rule, ctx); + violation = evaluateRule(rule, { ...ctx, advisory: severity !== 'error' }); } catch (err) { // Defensive: a broken rule must never brick a write. opts.logger?.warn?.(`Validation rule '${rule.name}' threw — skipped`, err); @@ -3614,8 +3634,8 @@ export function evaluateValidationRules( if (!violation) continue; - const severity = rule.severity ?? 'error'; - if (severity !== 'error' && violation.constraint?.reason !== 'unevaluable') { + const unevaluable = violation.constraint?.reason === 'unevaluable'; + if (severity !== 'error' && !unevaluable) { advisories.push(advisoryEvent(rule, severity, violation)); } if (severity === 'error') { @@ -3628,16 +3648,22 @@ export function evaluateValidationRules( // row count and example rows. Off that path no scope is active, // `recordAdvisoryHit` returns false, and the per-write line below is // emitted verbatim — an ordinary interactive write is untouched. + // + // [#24782] An UNEVALUABLE advisory rule is reported through the same two + // outlets, once, but not with its violation's message: that text is the + // refusal an `error` rule returns ("… — write rejected."), false for a + // write this rule does not block. The evaluator logged nothing for it + // (see `failClosedLogger`), so this is its only line. !recordAdvisoryHit({ object: advisoryObjectName(objectSchema), rule: String(rule.name ?? '(unnamed)'), severity, - message: violation.message, + message: unevaluable ? unevaluableAdvisoryMessage(rule, violation) : violation.message, recordRef: advisoryRecordRef(merged, data), }) ) { opts.logger?.warn?.( - `Validation rule '${rule.name}' (${severity}): ${violation.message}`, + `Validation rule '${rule.name}' (${severity}): ${unevaluable ? unevaluableAdvisoryMessage(rule, violation) : violation.message}`, ); } } @@ -3646,6 +3672,20 @@ export function evaluateValidationRules( return advisories; } +/** + * [#24782] What an advisory rule that could not be EVALUATED reports, in place + * of its violation's message: the fault, and that the write proceeded — the + * rule is advisory, so having no verdict does not block (#4649 fails closed on + * `severity: 'error'` only). Names the branch when the fault is a + * `conditional`'s branch rather than the rule itself. + */ +function unevaluableAdvisoryMessage(rule: BaseRule, violation: FieldValidationError): string { + const faulted = violation.constraint?.rule; + const subject = typeof faulted === 'string' && faulted !== rule.name ? `its branch '${faulted}'` : 'the rule'; + return `${subject} could not be evaluated (${String(violation.constraint?.fault)})` + + ' — write proceeded: the rule is advisory, so it was not applied to this write'; +} + /** * [#22726] One advisory hit as the event the write reports it through. Every * member is copied from the evaluation's own verdict — the violation the rule @@ -3753,7 +3793,7 @@ function evaluateRule(rule: BaseRule, ctx: RuleContext): FieldValidationError | return checkStateMachine(rule as StateMachineRule, ctx.mode, ctx.data, ctx.previous, ctx); case 'script': case 'cross_field': - return checkPredicate(rule as PredicateRule, ctx.merged, ctx.previous, ctx.logger, ctx.messages, ctx.related, ctx.fields); + return checkPredicate(rule as PredicateRule, ctx.merged, ctx.previous, failClosedLogger(ctx), ctx.messages, ctx.related, ctx.fields); case 'format': return checkFormat(rule as FormatRule, ctx.data, ctx.logger, ctx.messages); case 'json_schema': @@ -4689,13 +4729,13 @@ function checkConditional( let record = ctx.merged; if (typeof expr.source === 'string' && expr.dialect === 'cel') { const scope = resolveTraversalScope(record, expr.source, ctx.related, ctx.fields); - if (!scope.ok) return traversalScopeRefusal(rule.name, '_record', scope, 'when-predicate', ctx.logger); + if (!scope.ok) return traversalScopeRefusal(rule.name, '_record', scope, 'when-predicate', failClosedLogger(ctx)); record = scope.record; } const result = ExpressionEngine.evaluate(expr, ruleScope(record, ctx.previous)); if (!result.ok) { - ctx.logger?.warn?.( + failClosedLogger(ctx)?.warn?.( `Validation rule '${rule.name}' when-predicate failed to evaluate (${result.error.kind}: ${result.error.message}) — write rejected: a rule that cannot be evaluated fails closed, it is never skipped`, ); const nullRead = nullPreviousReadDetail(result.error, rule.when, ctx.previous, ctx.fields, 'when-predicate');