From e93b5c0c5791e99359332c7ef9a3795575ccfde5 Mon Sep 17 00:00:00 2001 From: David Waltermire Date: Sun, 8 Feb 2026 14:05:53 -0500 Subject: [PATCH] feat: add performance instrumentation for constraint processing (#314) Add event-based timing instrumentation to the constraint validation pipeline, exposed through SARIF 2.1.0 output via a new --sarif-timing CLI option. Core infrastructure: - Rename ParallelValidationConfig to ValidationConfig with listener support - Add ValidationEventListener interface, NoOp implementation, and ValidationPhase enum for overall/phase/constraint/let-statement events - Add getInternalIdentifier() to IConstraint and ILet with deterministic fallback identifiers and lazy caching Timing collection: - Add TimingRecord with thread-safe accumulators (LongAdder, AtomicLong, AtomicReference with CAS loops) - Add TimingCollector implementing ValidationEventListener with hierarchical storage for phase, constraint, and let-statement timing - Wire event firing into DefaultConstraintValidator constraint and let-statement evaluation loops SARIF integration and CLI: - Extend SARIF module with invocation, notification, and timing types - Add timing enrichment to SarifValidationHandler (invocation timestamps, phase notifications, per-constraint rule timing) - Add ValidationFeature.EVENT_LISTENER for configuration propagation - Add --sarif-timing CLI option (requires -o for SARIF output file) Code generation: - Add AnyInstanceTypeInfoImpl for @BoundAny field generation Documentation: - Add PRD and implementation plan - Add website guides for CLI reference, SARIF output format, and constraint validation with performance instrumentation - Add SARIF compliance Claude rule with schema validation requirements --- .claude/rules/sarif-compliance.md | 64 ++ PRDs/20260207-constraint-timing/PRD.md | 311 ++++++++++ .../implementation-plan.md | 346 +++++++++++ .../CompositeValidationEventListener.java | 93 +++ .../DefaultConstraintValidator.java | 86 ++- .../core/model/constraint/IConstraint.java | 23 + .../core/model/constraint/ILet.java | 19 + .../NoOpValidationEventListener.java | 63 ++ .../model/constraint/TimingCollector.java | 232 +++++++ .../core/model/constraint/TimingRecord.java | 144 +++++ ...ationConfig.java => ValidationConfig.java} | 94 ++- .../constraint/ValidationEventListener.java | 96 +++ .../model/constraint/ValidationFeature.java | 14 + .../model/constraint/ValidationPhase.java | 20 + .../constraint/impl/AbstractConstraint.java | 13 + .../model/constraint/impl/DefaultLet.java | 13 + .../CompositeValidationEventListenerTest.java | 105 ++++ .../constraint/ConstraintIdentifierTest.java | 156 +++++ ...ltConstraintValidatorThreadSafetyTest.java | 6 +- .../ParallelValidationConfigTest.java | 88 --- .../model/constraint/TimingCollectorTest.java | 297 +++++++++ .../constraint/ValidationConfigTest.java | 216 +++++++ databind-modules/modules | 2 +- databind-modules/pom.xml | 1 - .../modules/sarif/SarifValidationHandler.java | 348 ++++++++++- .../SarifValidationHandlerTimingTest.java | 573 ++++++++++++++++++ .../metaschema/databind/IBindingContext.java | 20 +- .../typeinfo/AnyInstanceTypeInfoImpl.java | 21 + metaschema-cli/pom.xml | 7 +- .../AbstractValidateContentCommand.java | 70 ++- metaschema-cli/src/main/java/module-info.java | 1 + .../test/java/dev/metaschema/cli/CLITest.java | 170 ++++++ .../content/timing-test-constraints.xml | 16 + .../content/timing-test-content.json | 23 + .../resources/content/timing-test-module.xml | 37 ++ pom.xml | 6 + src/site/markdown/guides/sarif-output.md.vm | 329 ++++++++++ src/site/markdown/guides/using-the-cli.md.vm | 322 ++++++++++ .../guides/validating-with-constraints.md.vm | 210 ++++++- src/site/site.xml | 2 + 40 files changed, 4515 insertions(+), 142 deletions(-) create mode 100644 .claude/rules/sarif-compliance.md create mode 100644 PRDs/20260207-constraint-timing/PRD.md create mode 100644 PRDs/20260207-constraint-timing/implementation-plan.md create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/CompositeValidationEventListener.java create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/NoOpValidationEventListener.java create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/TimingCollector.java create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/TimingRecord.java rename core/src/main/java/dev/metaschema/core/model/constraint/{ParallelValidationConfig.java => ValidationConfig.java} (55%) create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/ValidationEventListener.java create mode 100644 core/src/main/java/dev/metaschema/core/model/constraint/ValidationPhase.java create mode 100644 core/src/test/java/dev/metaschema/core/model/constraint/CompositeValidationEventListenerTest.java create mode 100644 core/src/test/java/dev/metaschema/core/model/constraint/ConstraintIdentifierTest.java delete mode 100644 core/src/test/java/dev/metaschema/core/model/constraint/ParallelValidationConfigTest.java create mode 100644 core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorTest.java create mode 100644 core/src/test/java/dev/metaschema/core/model/constraint/ValidationConfigTest.java create mode 100644 databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java create mode 100644 metaschema-cli/src/test/resources/content/timing-test-constraints.xml create mode 100644 metaschema-cli/src/test/resources/content/timing-test-content.json create mode 100644 metaschema-cli/src/test/resources/content/timing-test-module.xml create mode 100644 src/site/markdown/guides/sarif-output.md.vm create mode 100644 src/site/markdown/guides/using-the-cli.md.vm diff --git a/.claude/rules/sarif-compliance.md b/.claude/rules/sarif-compliance.md new file mode 100644 index 0000000000..163f48d2ec --- /dev/null +++ b/.claude/rules/sarif-compliance.md @@ -0,0 +1,64 @@ +# SARIF Compliance + +## Standard Compliance Required (BLOCKING) + +All SARIF output produced by this project MUST conform to the [SARIF 2.1.0 specification](https://docs.oasis-open.org/sarif/sarif/v2.1.0/sarif-v2.1.0.html). + +## Official Schema Location + +The official SARIF 2.1.0 JSON schema is stored locally at: + +```text +databind-modules/modules/sarif/sarif-schema-2.1.0.json +``` + +This is the authoritative reference for validating SARIF output. + +## Model Alignment + +The SARIF Metaschema module (`databind-modules/modules/sarif/sarif-module.xml`) models a subset of the SARIF 2.1.0 specification: + +- All modeled types MUST use the exact field names and types from the SARIF spec +- Required fields in the SARIF spec MUST be marked with `min-occurs="1"` in the module +- Optional SARIF fields MAY be omitted from the module (partial models are acceptable) +- No custom assembly or field types that don't exist in SARIF 2.1.0 + +## Extension Points + +The SARIF specification defines `propertyBag` with `additionalProperties: true` as the standard extension mechanism for tool-specific data. Using `propertyBag` for custom properties (e.g., timing data) is standard-compliant and NOT a model extension. + +## Testing Requirements + +Any code that produces SARIF output MUST include a test that validates the output against the official schema at `databind-modules/modules/sarif/sarif-schema-2.1.0.json`. + +### Validation Pattern + +```java +// Path is relative to databind-modules/ working directory +Path sarifSchema = Paths.get("modules/sarif/sarif-schema-2.1.0.json"); + +try (Reader schemaReader = Files.newBufferedReader(sarifSchema, StandardCharsets.UTF_8)) { + JsonNode schemaNode = new OrgJsonNode(new JSONObject(new JSONTokener(schemaReader))); + JsonNode instanceNode = new OrgJsonNode(new JSONObject(sarifOutput)); + + Validator.Result result = new ValidatorFactory() + .withJsonNodeFactory(new OrgJsonNode.Factory()) + .withDialect(new Dialects.Draft2020Dialect()) + .validate(schemaNode, instanceNode); + assertTrue(result.isValid(), "SARIF output failed schema validation"); +} +``` + +## Existing SARIF Tests + +| Test Class | What It Validates | +|------------|-------------------| +| `SarifValidationHandlerTest` | Core SARIF output structure and schema compliance | +| `SarifValidationHandlerTimingTest` | Timing enrichment and schema compliance with timing data | + +## When Modifying SARIF Output + +1. Check the official schema for field names, types, and required status +2. Update the Metaschema module if adding new SARIF types +3. Add or update schema validation tests +4. Verify output passes the official SARIF 2.1.0 JSON schema diff --git a/PRDs/20260207-constraint-timing/PRD.md b/PRDs/20260207-constraint-timing/PRD.md new file mode 100644 index 0000000000..5e9628e2b5 --- /dev/null +++ b/PRDs/20260207-constraint-timing/PRD.md @@ -0,0 +1,311 @@ +# PRD: Performance Instrumentation for Constraint Processing + +## Document Information + +| Field | Value | +|-------|-------| +| **PRD ID** | TIMING-001 | +| **Status** | Draft | +| **Created** | 2026-02-07 | +| **Last Updated** | 2026-02-10 | +| **Issue** | [#314](https://github.com/metaschema-framework/metaschema-java/issues/314) | + +--- + +## 1. Overview + +### 1.1 Problem Statement + +Developers working with Metaschema-enabled software have no way to measure the performance of individual constraint evaluations or overall constraint processing. When validation is slow, there is no built-in mechanism to identify which constraints or let-statement evaluations are hotspots. This makes performance optimization guesswork rather than data-driven. + +### 1.2 Goals + +1. Add event-based instrumentation to the constraint validation pipeline +2. Collect per-constraint, per-let-statement, per-phase, and overall validation timing data +3. Expose timing data through SARIF 2.1.0 output using both native timestamp fields and custom properties +4. Provide a CLI flag (`--sarif-timing`) to opt into detailed timing collection +5. Always include overall run timing in SARIF output regardless of `--sarif-timing` +6. Attach per-evaluation timing (constraint duration and let-statement breakdown) to individual SARIF results +7. Ensure zero overhead when timing is disabled + +### 1.3 Non-Goals + +- OpenTelemetry or external APM integration (future work) +- Console-readable timing output (future work, can reuse `TimingCollector`) +- Profiling of Metapath expression evaluation outside of let-statements +- Historical performance tracking or benchmarking infrastructure + +### 1.4 Success Metrics + +| Metric | Current | Target | +|--------|---------|--------| +| Per-constraint timing available | No | Yes, via SARIF rule properties | +| Per-result evaluation timing | No | Yes, via SARIF result properties | +| Per-result let-statement timing | No | Yes, via SARIF result properties | +| Let-statement timing available | No | Yes, via SARIF notifications | +| Phase-level timing available | No | Yes, via SARIF invocation | +| Overall run timing in SARIF | No | Yes, always (no flag needed) | +| Overhead when disabled | N/A | Zero (no-op listener) | +| Overhead when enabled | N/A | < 5% wall-clock increase | + +--- + +## 2. Background + +### 2.1 Current State + +The metaschema-java framework includes: + +- **SARIF 2.1.0 output** via `SarifValidationHandler` in `databind-modules`, supporting constraint findings, schema validation findings, and rule descriptors +- **Constraint validation pipeline** with `DefaultConstraintValidator`, the `IConstraintValidationHandler` callback pattern, and parallel execution via `ParallelValidationConfig` +- **CLI integration** with `--threads` for parallel validation and `-o` for SARIF output +- **No timing or instrumentation** of any kind in the validation pipeline + +### 2.2 Technical Context + +**Key classes involved:** + +| Class | Module | Role | +|-------|--------|------| +| `DefaultConstraintValidator` | core | Main constraint evaluation engine | +| `IConstraintValidator` | core | Validator interface | +| `IConstraintValidationHandler` | core | Callback interface for findings | +| `FindingCollectingConstraintValidationHandler` | core | Collects findings for result aggregation | +| `ParallelValidationConfig` | core | Thread pool configuration | +| `DynamicContext` | core | Metapath evaluation context (let bindings) | +| `SarifValidationHandler` | databind-modules | SARIF document generation | +| `AbstractValidateContentCommand` | metaschema-cli | CLI validation commands | + +**SARIF 2.1.0 built-in timing fields:** + +| Object | Property | Type | +|--------|----------|------| +| `invocation` | `startTimeUtc` / `endTimeUtc` | datetime | +| `notification` | `timeUtc` | datetime | + +SARIF has no built-in duration fields. Duration metrics must use `properties` bags per the specification's extensibility model. + +**Thread safety:** Constraint validation supports parallel execution. All timing collection must be thread-safe. + +--- + +## 3. Requirements + +### 3.1 Functional Requirements + +#### FR-1: Event-Based Instrumentation + +A `ValidationEventListener` interface defines callbacks at four granularity levels: + +- **Overall:** `beforeValidation(URI)` / `afterValidation(URI)` +- **Phase:** `beforePhase(ValidationPhase)` / `afterPhase(ValidationPhase)` where `ValidationPhase` is an enum: `SCHEMA_VALIDATION`, `CONSTRAINT_VALIDATION`, `FINALIZATION` +- **Constraint:** `beforeConstraintEvaluation(IConstraint, INodeItem)` / `afterConstraintEvaluation(IConstraint, INodeItem)` +- **Let-statement:** `beforeLetEvaluation(ILet)` / `afterLetEvaluation(ILet)` + +A `NoOpValidationEventListener` provides empty implementations for all methods. + +#### FR-2: Validation Configuration + +Rename `ParallelValidationConfig` to `ValidationConfig`. Retain existing `withThreads()` and `withExecutor()` builder methods. Add `addListener(ValidationEventListener)` method (supports multiple listeners via composite pattern). Default listener is the no-op implementation. When multiple listeners are registered, a `CompositeValidationEventListener` delegates to all of them in registration order. + +#### FR-3: Timing Collection + +A `TimingCollector` class implements `ValidationEventListener` and records: + +- **`TimingRecord`** for each entry: `totalTimeNs`, `count`, `minTimeNs`, `maxTimeNs`, `startTimestampUtc`, `endTimestampUtc` +- **Hierarchical storage:** separate maps for phase timings (`Map`), constraint timings (`Map`), and let timings (`Map`), plus an overall `validationTiming` record +- **Thread safety:** Thread-local deques for start times (handles nested events); concurrent maps for accumulation +- **Nanosecond precision** via `System.nanoTime()` for durations; `Instant.now()` for UTC timestamps + +#### FR-4: Identifier Strategy + +Both `IConstraint` and `ILet` expose a `getInternalIdentifier()` method using lazy compute + cache: + +- **Constraints:** Author-defined `id` if present; deterministic fallback `{module-short-name}-{definition-name}-{constraint-type}-{index}` +- **Let statements:** Deterministic `{module-short-name}-{definition-name}-let-{name}` + +#### FR-5: SARIF Aggregate Timing Enrichment + +When a `TimingCollector` is available, `SarifValidationHandler` produces enriched SARIF: + +- **Invocation level:** Populate phase timing as `toolExecutionNotifications[]` with per-phase `properties.timing` +- **Rule level:** Add `properties.timing` to each rule in `tool.driver.rules[]` with `totalMs`, `count`, `minMs`, `maxMs` +- **Notifications level:** Add `toolExecutionNotifications[]` entries for each let evaluation with `timeUtc`, `descriptor.id`, `message.text`, and `properties.timing` containing `totalMs`, `count`, `minMs`, `maxMs` + +When no `TimingCollector` is provided, aggregate timing enrichment is omitted. + +#### FR-6: CLI Integration + +New CLI option `--sarif-timing` on validation commands: + +- Requires `-o` (SARIF output file); error if used without it +- When present, creates a `TimingCollector` and wires it into `ValidationConfig` +- Also registers `SarifValidationHandler` as a `ValidationEventListener` for per-result timing +- Timing data appears in the SARIF output file + +#### FR-7: Always-On Run Timing + +The SARIF output must always include an `invocation` object with overall run timing, regardless of whether `--sarif-timing` is used: + +- `invocation.startTimeUtc`: recorded when `SarifValidationHandler` is constructed +- `invocation.endTimeUtc`: recorded when `generateSarif()` is called +- `invocation.executionSuccessful`: always set to `true` + +This provides basic performance visibility without requiring any CLI flag. + +#### FR-8: Per-Result Evaluation Timing + +When `--sarif-timing` is enabled, each SARIF `result` object includes the duration of the specific constraint evaluation that produced it: + +- Timing is attached via `result.properties` (propertyBag), per SARIF 2.1.0 section 3.8 +- Uses the existing `TimingData` structure within the property bag + +```json +{ + "ruleId": "require-title", + "message": { "text": "..." }, + "properties": { + "timing": { + "totalMs": 0.307, + "count": 1, + "minMs": 0.307, + "maxMs": 0.307 + } + } +} +``` + +Implementation approach: `SarifValidationHandler` implements `ValidationEventListener` and uses thread-local state to track the current constraint evaluation start time. When a finding callback is received during evaluation, the handler associates the finding with the current evaluation. In `afterConstraintEvaluation()`, the handler computes the evaluation duration and records it on all findings from that evaluation. + +#### FR-9: Per-Result Let-Statement Timing + +When `--sarif-timing` is enabled, each SARIF `result` also includes timing data for let-statement evaluations that occurred during the constraint evaluation that produced it: + +- Let timings are attached in `result.properties.letTimings` as an array of entries +- Each entry includes the let-statement name and its `TimingData` + +```json +{ + "properties": { + "timing": { "totalMs": 0.307, "count": 1, "minMs": 0.307, "maxMs": 0.307 }, + "letTimings": [ + { + "name": "target-items", + "timing": { "totalMs": 0.25, "count": 1, "minMs": 0.25, "maxMs": 0.25 } + } + ] + } +} +``` + +The SARIF 2.1.0 propertyBag specification (`additionalProperties: true`) permits arbitrary key-value pairs, making this standards-compliant without schema modification. + +#### FR-10: Multi-Listener Event Delivery + +The validation event infrastructure must support delivering events to multiple listeners simultaneously. When `--sarif-timing` is used, both the `TimingCollector` (for aggregate timing on rules/phases/notifications) and the `SarifValidationHandler` (for per-result timing) receive events: + +- `CompositeValidationEventListener` delegates to a list of listeners +- `ValidationConfig.addListener()` registers additional listeners +- Events are delivered in registration order to all listeners + +### 3.2 Non-Functional Requirements + +#### NFR-1: Zero Overhead When Disabled + +The no-op listener must introduce no measurable overhead. No object allocation, no map lookups, no `System.nanoTime()` calls when timing is disabled. + +#### NFR-2: Thread Safety + +All timing collection must be safe under parallel constraint validation. Use `ConcurrentHashMap`, thread-local deques, and atomic operations as needed. + +#### NFR-3: Backward Compatibility + +The rename of `ParallelValidationConfig` to `ValidationConfig` is a breaking change. All existing callers must be updated. The existing builder API (`withThreads()`, `withExecutor()`, `SEQUENTIAL`) must continue to function identically. + +--- + +## 4. Implementation Phases + +### Phase 1: Core Infrastructure + +Rename `ParallelValidationConfig` to `ValidationConfig`. Define `ValidationEventListener` interface, no-op implementation, and `ValidationPhase` enum. Add `withListener()` to `ValidationConfig`. Add `getInternalIdentifier()` to `IConstraint` and `ILet` with lazy caching. + +### Phase 2: Timing Collection + +Implement `TimingCollector` with hierarchical storage, thread-safe accumulation, and `TimingRecord`. Wire event firing into `DefaultConstraintValidator` and let-evaluation code paths. + +### Phase 3: SARIF Integration & CLI + +Extend `SarifValidationHandler` to consume `TimingCollector` data. Add `--sarif-timing` CLI option. End-to-end integration. + +### Phase 4: Per-Result Timing & Always-On Run Timing + +Add always-on invocation timing (FR-7). Implement `SarifValidationHandler` as a `ValidationEventListener` for per-result evaluation timing (FR-8) and per-result let-statement timing (FR-9). Add `CompositeValidationEventListener` for multi-listener support (FR-10). Extend the SARIF module to support `propertyBag` on result objects. Update CLI wiring to register both `TimingCollector` and `SarifValidationHandler` as event listeners. + +--- + +## 5. Testing Strategy + +### 5.1 Test Approach + +All code changes follow TDD. Tests are written before implementation at each phase. + +### 5.2 Unit Tests + +| Component | Test Focus | +|-----------|-----------| +| `TimingCollector` | Accumulates timing correctly; thread-safety under concurrent events; min/max/count tracking; nested deque handling | +| `NoOpValidationEventListener` | All methods callable without error | +| `ValidationConfig` | Builder produces correct config; default listener is no-op; existing `withThreads()` API unchanged | +| Identifier generation | Explicit IDs used when present; deterministic fallback computed correctly; lazy caching returns same instance | +| `SarifValidationHandler` | With collector: timing properties at all three levels; without collector: output unchanged; millisecond conversion correct; UTC timestamps populated | +| `SarifValidationHandler` (per-result) | Per-result evaluation timing attached to `result.properties.timing`; per-result let timings in `result.properties.letTimings`; SARIF schema compliance | +| `SarifValidationHandler` (always-on) | Invocation with `startTimeUtc`/`endTimeUtc` always present in SARIF output even without `--sarif-timing` | +| `CompositeValidationEventListener` | Events delivered to all registered listeners in order | +| CLI `--sarif-timing` | Accepted with `-o`; error without `-o`; timing data in output file | + +### 5.3 Integration Test + +End-to-end test that validates a document with known constraints and let statements, captures SARIF output with `--sarif-timing`, and verifies: + +- Timing values are positive and plausible +- All constraint identifiers appear in rule timing +- Let evaluation notifications present +- Phase timing covers all phases +- `startTimeUtc` < `endTimeUtc` +- Each result has `properties.timing` with per-evaluation duration +- Results from constraints with let statements include `properties.letTimings` +- SARIF output without `--sarif-timing` still includes invocation with timestamps + +### 5.4 Verification Checklist + +- [ ] All existing tests pass (no regressions from rename) +- [ ] New unit tests for all components +- [ ] Integration test passes +- [ ] `mvn clean install -PCI -Prelease` succeeds +- [ ] SARIF output validates against SARIF 2.1.0 schema + +--- + +## 6. Risks and Mitigations + +| Risk | Impact | Likelihood | Mitigation | +|------|--------|------------|------------| +| Rename breaks downstream consumers | Medium | Medium | Update all references in metaschema-java; document in release notes | +| Thread-local deque leaks on exception | Low | Low | Use try-finally in event firing; clear thread-locals in `afterValidation` | +| `System.nanoTime()` overhead in hot path | Low | Low | Only called when timing enabled; no-op listener is default | +| Let-evaluation instrumentation requires changes to Metapath context | Medium | Medium | Careful scoping of changes to let-binding evaluation only | + +--- + +## 7. Open Questions + +None — all design decisions resolved during brainstorming. + +--- + +## 8. Related Documents + +- [Implementation Plan](./implementation-plan.md) +- [Issue #314](https://github.com/metaschema-framework/metaschema-java/issues/314) +- [SARIF 2.1.0 Specification](https://docs.oasis-open.org/sarif/sarif/v2.1.0/sarif-v2.1.0.html) diff --git a/PRDs/20260207-constraint-timing/implementation-plan.md b/PRDs/20260207-constraint-timing/implementation-plan.md new file mode 100644 index 0000000000..656041899c --- /dev/null +++ b/PRDs/20260207-constraint-timing/implementation-plan.md @@ -0,0 +1,346 @@ +# Implementation Plan: Performance Instrumentation for Constraint Processing + +This document details each PR for the constraint timing instrumentation initiative. + +--- + +## Prerequisites + +- Working build from `develop` branch +- Git worktree created for this feature + +--- + +## Test-Driven Development Requirement + +**All functional code changes must follow TDD:** + +1. Write or update tests first to capture expected behavior +2. Verify tests fail for the expected reason +3. Make the code changes +4. Verify tests pass after changes + +--- + +## Phase 1: Core Infrastructure + +### PR 1: Rename `ParallelValidationConfig` to `ValidationConfig` and Add Event Listener Support + +| Attribute | Value | +|-----------|-------| +| **Files Changed** | ~15 | +| **Risk Level** | Medium | +| **Dependencies** | None | +| **Target Branch** | develop | +| **Status** | Complete | +| **Commit** | `45ee1c63d` | + +#### Files to Modify + +| File | Changes | +|------|---------| +| `core/src/main/java/dev/metaschema/core/model/constraint/ParallelValidationConfig.java` | Rename to `ValidationConfig.java`; add `withListener(ValidationEventListener)` builder method; default to `NoOpValidationEventListener` | +| `core/src/main/java/dev/metaschema/core/model/constraint/ValidationEventListener.java` | **New file.** Interface with `beforeValidation`, `afterValidation`, `beforePhase`, `afterPhase`, `beforeConstraintEvaluation`, `afterConstraintEvaluation`, `beforeLetEvaluation`, `afterLetEvaluation` | +| `core/src/main/java/dev/metaschema/core/model/constraint/NoOpValidationEventListener.java` | **New file.** Empty implementation of all `ValidationEventListener` methods | +| `core/src/main/java/dev/metaschema/core/model/constraint/ValidationPhase.java` | **New file.** Enum: `SCHEMA_VALIDATION`, `CONSTRAINT_VALIDATION`, `FINALIZATION` | +| `core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java` | Update imports from `ParallelValidationConfig` to `ValidationConfig`; update constructor and field references | +| `core/src/test/java/dev/metaschema/core/model/constraint/ParallelValidationConfigTest.java` | Rename to `ValidationConfigTest.java`; add tests for `withListener()` and default no-op listener | +| `core/src/test/java/dev/metaschema/core/model/constraint/DefaultConstraintValidatorThreadSafetyTest.java` | Update references from `ParallelValidationConfig` to `ValidationConfig` | +| `databind/src/main/java/dev/metaschema/databind/IBindingContext.java` | Update `ParallelValidationConfig` references to `ValidationConfig` | +| Any other files referencing `ParallelValidationConfig` | Update imports and references | + +#### Acceptance Criteria + +- [x] `ParallelValidationConfig` renamed to `ValidationConfig` across all files +- [x] `ValidationEventListener` interface defined with all 8 event methods +- [x] `NoOpValidationEventListener` provides empty implementations +- [x] `ValidationPhase` enum created with `SCHEMA_VALIDATION`, `CONSTRAINT_VALIDATION`, `FINALIZATION` +- [x] `ValidationConfig.withListener()` builder method works correctly +- [x] Default listener is `NoOpValidationEventListener` +- [x] Existing `withThreads()` and `withExecutor()` API unchanged +- [x] `SEQUENTIAL` static instance continues to work +- [x] All existing tests pass (no regressions) +- [x] New tests for `ValidationConfig.withListener()` and no-op default +- [x] Build succeeds: `mvn clean install -PCI -Prelease` + +--- + +### PR 2: Add Identifiers to Constraints and Let Statements + +| Attribute | Value | +|-----------|-------| +| **Files Changed** | ~8 | +| **Risk Level** | Low | +| **Dependencies** | PR 1 | +| **Target Branch** | develop | +| **Status** | Complete | +| **Commit** | `e2c827b52` | + +#### Files to Modify + +| File | Changes | +|------|---------| +| `core/src/main/java/dev/metaschema/core/model/constraint/IConstraint.java` | Add `getInternalIdentifier()` default method | +| `core/src/main/java/dev/metaschema/core/model/constraint/ILet.java` | Add `getInternalIdentifier()` default method | +| `core/src/main/java/dev/metaschema/core/model/constraint/AbstractConstraint.java` | Implement `getInternalIdentifier()` with lazy compute + cache | +| `core/src/main/java/dev/metaschema/core/model/constraint/DefaultLet.java` | Implement `getInternalIdentifier()` with lazy compute + cache | +| `core/src/test/java/dev/metaschema/core/model/constraint/IConstraintIdentifierTest.java` | **New file.** Tests for identifier generation | +| `core/src/test/java/dev/metaschema/core/model/constraint/ILetIdentifierTest.java` | **New file.** Tests for let identifier generation | + +#### Acceptance Criteria + +- [x] `IConstraint.getInternalIdentifier()` returns author-defined `id` when present +- [x] `IConstraint.getInternalIdentifier()` returns deterministic fallback when `id` is null +- [x] `ILet.getInternalIdentifier()` returns deterministic scoped identifier +- [x] Identifiers are lazily computed and cached (same instance on repeated calls) +- [x] Unit tests cover explicit ID, fallback, and caching scenarios +- [x] All existing tests pass +- [x] Build succeeds: `mvn clean install -PCI -Prelease` + +--- + +## Phase 2: Timing Collection + +### PR 3: Implement `TimingCollector` and Wire Event Firing + +| Attribute | Value | +|-----------|-------| +| **Files Changed** | ~10 | +| **Risk Level** | Medium | +| **Dependencies** | PR 1, PR 2 | +| **Target Branch** | develop | +| **Status** | Complete | +| **Commit** | `f82f14a94` | + +#### Files to Modify + +| File | Changes | +|------|---------| +| `core/src/main/java/dev/metaschema/core/model/constraint/TimingCollector.java` | **New file.** Implements `ValidationEventListener`; hierarchical storage with ConcurrentHashMaps and ThreadLocal deques | +| `core/src/main/java/dev/metaschema/core/model/constraint/TimingRecord.java` | **New file.** Record class with `totalTimeNs`, `count`, `minTimeNs`, `maxTimeNs`, `startTimestampUtc`, `endTimestampUtc` | +| `core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java` | Fire `beforeConstraintEvaluation`/`afterConstraintEvaluation` wrapping each constraint evaluation; fire `beforeLetEvaluation`/`afterLetEvaluation` in `handleLetStatements()` | +| `core/src/main/java/dev/metaschema/core/model/constraint/ValidationFeature.java` | **New file.** Add `EVENT_LISTENER` feature for passing listener through `IConfiguration` | +| `databind/src/main/java/dev/metaschema/databind/IBindingContext.java` | Read `ValidationFeature.EVENT_LISTENER` and apply to `ValidationConfig` | +| `core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorTest.java` | **New file.** Tests: timing accumulation, min/max/count tracking, UTC timestamp recording | +| `core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorThreadSafetyTest.java` | **New file.** Concurrent access tests | + +#### Acceptance Criteria + +- [x] `TimingCollector` accumulates timing data correctly for all event types +- [x] `TimingRecord` tracks totalTimeNs, count, minTimeNs, maxTimeNs, startTimestampUtc, endTimestampUtc +- [x] Thread-safety verified under concurrent constraint evaluation +- [x] Nested events (constraint containing let evaluations) handled correctly via deque +- [x] Events fired from `DefaultConstraintValidator` for all constraint types +- [x] Events fired for let-statement evaluations in `handleLetStatements()` +- [x] No-op listener introduces no measurable overhead +- [x] All existing tests pass +- [x] Build succeeds: `mvn clean install -PCI -Prelease` + +--- + +## Phase 3: SARIF Integration & CLI + +### PR 4: SARIF Timing Output and `--sarif-timing` CLI Option + +| Attribute | Value | +|-----------|-------| +| **Files Changed** | ~15 | +| **Risk Level** | Medium | +| **Dependencies** | PR 3 | +| **Target Branch** | develop | +| **Status** | Complete | +| **Commits** | `4562769de`, `bc1b206bc` | + +#### Files to Modify + +| File | Changes | +|------|---------| +| `databind-modules/modules/sarif/sarif-module.xml` | **Submodule change.** Add `invocation`, `notification`, `reportingDescriptor.properties`, `run.invocations` SARIF types; fix `notification.message` `min-occurs="1"` per SARIF spec | +| `databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java` | Accept optional `TimingCollector`; implement `enrichWithTiming()` for invocation, rule, and notification timing | +| `metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java` | Add `SARIF_TIMING_OPTION` (`--sarif-timing`); create `TimingCollector` and wire events | +| `databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java` | **New file.** Tests for timing enrichment and SARIF schema compliance | +| `metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java` | Add `testSarifTimingOutput()` end-to-end integration test with SARIF schema validation | +| `metaschema-cli/src/test/resources/content/timing-test-module.xml` | **New file.** Test metaschema module with inline constraints and let statements | +| `metaschema-cli/src/test/resources/content/timing-test-constraints.xml` | **New file.** External constraints with let statements | +| `metaschema-cli/src/test/resources/content/timing-test-content.json` | **New file.** Test content matching the timing-test-module schema | +| `.claude/rules/sarif-compliance.md` | **New file.** Claude rule requiring SARIF 2.1.0 compliance | +| `pom.xml` | Add `dev.harrel:json-schema` to parent POM dependencyManagement | +| `databind-modules/pom.xml` | Remove hardcoded `json-schema` version (inherits from parent) | +| `metaschema-cli/pom.xml` | Add `json-schema` test dependency (inherits version from parent) | + +#### Deviations from Plan + +- PR 5 (end-to-end integration test) was merged into PR 4 as `testSarifTimingOutput()` in `CLITest.java` rather than a separate test class, since the test naturally fits with the CLI module tests +- SARIF module changes required a separate submodule PR (metaschema-modules PR #10) +- Added SARIF compliance Claude rule (`.claude/rules/sarif-compliance.md`) not originally planned +- Centralized `dev.harrel:json-schema` dependency version in parent POM + +#### Acceptance Criteria + +- [x] `SarifValidationHandler` accepts optional `TimingCollector` +- [x] Invocation includes `startTimeUtc`/`endTimeUtc` and phase timing notifications +- [x] Each constraint rule includes `properties.timing` with `totalMs`, `count`, `minMs`, `maxMs` +- [x] Let evaluations appear as `toolExecutionNotifications[]` with timing data +- [x] Without `TimingCollector`, SARIF output is identical to current behavior +- [x] `--sarif-timing` flag accepted when `-o` is present +- [x] `--sarif-timing` without `-o` produces a clear error message +- [x] Nanoseconds correctly converted to milliseconds in SARIF output +- [x] Integration test validates timing data at all SARIF levels +- [x] Integration test exercises inline and external let statements +- [x] SARIF output validates against official SARIF 2.1.0 JSON schema +- [x] All existing tests pass +- [x] Build succeeds: `mvn clean install -PCI -Prelease` + +--- + +## Phase 4: Per-Result Timing & Always-On Run Timing + +### PR 5: Always-On Run Timing, Per-Result Evaluation and Let-Statement Timing + +| Attribute | Value | +|-----------|-------| +| **Files Changed** | ~15 | +| **Risk Level** | Medium | +| **Dependencies** | PR 4 | +| **Target Branch** | develop | +| **Status** | Complete | + +#### Overview + +This PR addresses three gaps: + +1. **Always-on run timing**: SARIF output always includes `invocation.startTimeUtc`/`endTimeUtc` even without `--sarif-timing` +2. **Per-result evaluation timing**: Each SARIF `result` includes the duration of the specific constraint evaluation that produced it +3. **Per-result let-statement timing**: Each SARIF `result` includes timing data for let-statement evaluations that occurred during its constraint evaluation + +#### Architecture + +**Multi-listener support**: `SarifValidationHandler` implements `ValidationEventListener` to receive before/after events directly. A `CompositeValidationEventListener` delivers events to both `TimingCollector` (aggregate timing) and `SarifValidationHandler` (per-result timing). + +**Per-result timing flow**: + +```text +beforeConstraintEvaluation() + → SarifValidationHandler records thread-local start nanotime + → clears thread-local let timing map + → clears thread-local "current evaluation findings" list + ↓ + [beforeLetEvaluation() / afterLetEvaluation()] + → SarifValidationHandler accumulates per-let durations in thread-local map + ↓ + handler.handleXxxViolation() + → SarifValidationHandler.addConstraintValidationFinding() + → adds new ConstraintResult to thread-local "current evaluation findings" + ↓ +afterConstraintEvaluation() + → computes evaluation duration = nanoTime() - start + → snapshots thread-local let timing map + → sets evaluation duration + let timings on all ConstraintResults in current list +``` + +**SARIF compliance**: Per SARIF 2.1.0 section 3.8, `propertyBag` is the standard extensibility mechanism. The `result.properties` uses the same `TimingData` structure already used on rules and notifications. Let-statement timing is added as `properties.letTimings` — valid because `propertyBag` permits `additionalProperties: true`. + +#### Files to Modify + +| File | Changes | +|------|---------| +| `core/src/main/java/dev/metaschema/core/model/constraint/CompositeValidationEventListener.java` | **New file.** Delegates to multiple `ValidationEventListener` instances | +| `core/src/main/java/dev/metaschema/core/model/constraint/ValidationConfig.java` | Add `addListener()` method; build `CompositeValidationEventListener` when multiple listeners registered | +| `core/src/test/java/dev/metaschema/core/model/constraint/CompositeValidationEventListenerTest.java` | **New file.** Tests multi-listener delivery | +| `databind-modules/modules/sarif/sarif-module.xml` | **Submodule change.** Add `propertyBag` to `result` definition; add `letTimingEntry` assembly; add `letTimings` list to `PropertyBag` | +| `databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java` | Implement `ValidationEventListener`; add thread-local state for per-evaluation timing; always create `Invocation` with timestamps; attach per-result timing and let timings during `generateResults()` | +| `databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java` | Add tests for per-result timing, per-result let timing, and always-on invocation timing | +| `metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java` | Register `SarifValidationHandler` as second event listener alongside `TimingCollector`; always record run timestamps | +| `metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java` | Add tests verifying invocation always present in SARIF output; per-result timing in `--sarif-timing` output | + +#### SARIF Module Changes (Submodule) + +Changes to `sarif-module.xml`: + +1. Add `` to the `result` definition (line ~252, inside ``) +2. Add `letTimingEntry` assembly definition: + +```xml + + Let Statement Timing Entry + Timing data for a single let-statement evaluation. + + Let Statement Name + The name of the let-statement variable. + + + + Timing Data + Performance timing measurements for this let-statement. + timing + + + +``` + +3. Add `letTimings` to `PropertyBag` model: + +```xml + + Let Statement Timings + Per-let-statement timing data for the associated constraint evaluation. + + +``` + +After modifying the submodule, regenerate binding classes: + +```bash +mvn install -DskipTests +mvn -f databind-modules/pom.xml generate-sources +``` + +#### Thread-Local State in SarifValidationHandler + +```java +// Per-evaluation timing state (thread-local for parallel validation) +private final ThreadLocal currentEvaluationStartNanos = new ThreadLocal<>(); +private final ThreadLocal> currentLetStartNanos = new ThreadLocal<>(); +private final ThreadLocal> currentLetDurations + = ThreadLocal.withInitial(LinkedHashMap::new); +private final ThreadLocal> currentEvaluationResults + = ThreadLocal.withInitial(ArrayList::new); + +// Always-on run timing +private final Instant constructionTimestamp = Instant.now(); +``` + +#### Deviations from Plan + +- Thread-local let duration tracking uses `Map` instead of `Map` for type safety +- Added `ConcurrentHashMap` for deferred timing lookup when findings are added after validation completes (CLI pattern) +- `--sarif-timing` option marked as experimental per user request +- CLI wires `SarifValidationHandler` as second event listener via `CompositeValidationEventListener` for per-result timing delivery + +#### Acceptance Criteria + +- [x] `CompositeValidationEventListener` delivers events to all registered listeners +- [x] `ValidationConfig.addListener()` supports registering multiple listeners +- [x] SARIF output always includes `invocation` with `startTimeUtc`/`endTimeUtc` even without `--sarif-timing` +- [x] Each SARIF `result` includes `properties.timing` with per-evaluation duration when `--sarif-timing` is used +- [x] Each SARIF `result` includes `properties.letTimings` for let-statements evaluated during its constraint evaluation +- [x] `result.properties` uses the standard SARIF `propertyBag` extensibility mechanism +- [x] Per-result timing is thread-safe under parallel validation +- [x] SARIF output validates against official SARIF 2.1.0 JSON schema +- [x] All existing tests pass +- [x] Build succeeds: `mvn clean install -PCI -Prelease` + +--- + +## PR Summary Table + +| PR | Description | Commit | Status | +|----|-------------|--------|--------| +| 1 | Rename `ParallelValidationConfig` to `ValidationConfig`; add event listener support | `45ee1c63d` | Complete | +| 2 | Add identifiers to constraints and let statements | `e2c827b52` | Complete | +| 3 | Implement `TimingCollector` and wire event firing | `f82f14a94` | Complete | +| 4 | SARIF timing output, `--sarif-timing` CLI option, and integration tests | `4562769de`, `bc1b206bc` | Complete | +| 5 | Always-on run timing, per-result evaluation and let-statement timing | — | Complete | + +**Pull Request**: https://github.com/metaschema-framework/metaschema-java/pull/658 +**Submodule PR**: https://github.com/metaschema-framework/metaschema-modules/pull/10 diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/CompositeValidationEventListener.java b/core/src/main/java/dev/metaschema/core/model/constraint/CompositeValidationEventListener.java new file mode 100644 index 0000000000..1935b33be0 --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/CompositeValidationEventListener.java @@ -0,0 +1,93 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import java.net.URI; +import java.util.List; + +import dev.metaschema.core.metapath.item.node.INodeItem; +import edu.umd.cs.findbugs.annotations.NonNull; + +/** + * A {@link ValidationEventListener} that delegates all events to multiple + * listeners. + *

+ * This enables multiple independent consumers (e.g., {@link TimingCollector} + * for aggregate timing and a SARIF handler for per-result timing) to receive + * the same validation events. + * + * @see ValidationEventListener + */ +public class CompositeValidationEventListener implements ValidationEventListener { + @NonNull + private final List listeners; + + /** + * Construct a composite listener that delegates to the given listeners. + * + * @param listeners + * the listeners to delegate to, in order + */ + public CompositeValidationEventListener(@NonNull List listeners) { + this.listeners = List.copyOf(listeners); + } + + @Override + public void beforeValidation(@NonNull URI document) { + for (ValidationEventListener listener : listeners) { + listener.beforeValidation(document); + } + } + + @Override + public void afterValidation(@NonNull URI document) { + for (ValidationEventListener listener : listeners) { + listener.afterValidation(document); + } + } + + @Override + public void beforePhase(@NonNull ValidationPhase phase) { + for (ValidationEventListener listener : listeners) { + listener.beforePhase(phase); + } + } + + @Override + public void afterPhase(@NonNull ValidationPhase phase) { + for (ValidationEventListener listener : listeners) { + listener.afterPhase(phase); + } + } + + @Override + public void beforeConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + for (ValidationEventListener listener : listeners) { + listener.beforeConstraintEvaluation(constraint, target); + } + } + + @Override + public void afterConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + for (ValidationEventListener listener : listeners) { + listener.afterConstraintEvaluation(constraint, target); + } + } + + @Override + public void beforeLetEvaluation(@NonNull ILet let) { + for (ValidationEventListener listener : listeners) { + listener.beforeLetEvaluation(let); + } + } + + @Override + public void afterLetEvaluation(@NonNull ILet let) { + for (ValidationEventListener listener : listeners) { + listener.afterLetEvaluation(let); + } + } +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java b/core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java index aac496120a..4cda3cf75e 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/DefaultConstraintValidator.java @@ -77,7 +77,7 @@ public class DefaultConstraintValidator private final IMutableConfiguration> configuration; @NonNull @Owning - private final ParallelValidationConfig parallelConfig; + private final ValidationConfig validationConfig; /** * Construct a new constraint validation instance with sequential execution. @@ -87,23 +87,25 @@ public class DefaultConstraintValidator */ public DefaultConstraintValidator( @NonNull IConstraintValidationHandler handler) { - this(handler, ParallelValidationConfig.SEQUENTIAL); + this(handler, ValidationConfig.SEQUENTIAL); } /** - * Construct a new constraint validation instance with configurable parallelism. + * Construct a new constraint validation instance with the provided + * configuration. * * @param handler * the validation handler to use for handling constraint violations - * @param parallelConfig - * the parallel execution configuration + * @param validationConfig + * the validation configuration controlling parallelism and event + * instrumentation */ public DefaultConstraintValidator( @NonNull IConstraintValidationHandler handler, - @NonNull ParallelValidationConfig parallelConfig) { + @NonNull ValidationConfig validationConfig) { this.handler = handler; this.configuration = new DefaultConfiguration<>(); - this.parallelConfig = parallelConfig; + this.validationConfig = validationConfig; } /** @@ -163,9 +165,19 @@ protected IConstraintValidationHandler getConstraintValidationHandler() { return handler; } + /** + * Get the validation event listener from the configuration. + * + * @return the listener + */ + @NonNull + private ValidationEventListener getListener() { + return validationConfig.getListener(); + } + @Override public void close() { - parallelConfig.close(); + validationConfig.close(); } @Override @@ -283,13 +295,17 @@ private void validateHasCardinality( @NonNull List constraints, @NonNull IAssemblyNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (ICardinalityConstraint constraint : constraints) { assert constraint != null; + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateHasCardinality(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -354,14 +370,17 @@ private void validateIndex( @NonNull List constraints, @NonNull IAssemblyNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IIndexConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateIndex(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -498,14 +517,17 @@ private void validateUnique( @NonNull List constraints, @NonNull IAssemblyNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IUniqueConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateUnique(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -580,14 +602,17 @@ private void validateMatches( @NonNull IDefinitionNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IMatchesConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateMatches(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -670,14 +695,17 @@ private void validateIndexHasKey( @NonNull IDefinitionNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IIndexHasKeyConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateIndexHasKey(constraint, item, targets); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -728,14 +756,17 @@ private void validateExpect( @NonNull List constraints, @NonNull IDefinitionNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IExpectConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateExpect(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -804,14 +835,17 @@ private void validateReport( @NonNull List constraints, @NonNull IDefinitionNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IReportConstraint constraint : constraints) { assert constraint != null; - + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateReport(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -881,13 +915,17 @@ private void validateAllowedValues( @NonNull List constraints, @NonNull IDefinitionNodeItem item, @NonNull DynamicContext dynamicContext) throws ConstraintValidationException { + ValidationEventListener listener = getListener(); for (IAllowedValuesConstraint constraint : constraints) { assert constraint != null; + listener.beforeConstraintEvaluation(constraint, item); try { ISequence> targets = constraint.matchTargets(item, dynamicContext); validateAllowedValues(constraint, item, targets, dynamicContext); } catch (MetapathException ex) { handleError(constraint, item, ex, dynamicContext); + } finally { + listener.afterConstraintEvaluation(constraint, item); } } } @@ -1163,14 +1201,20 @@ private DynamicContext handleLetStatements( retval = dynamicContext; } else { final DynamicContext subContext = dynamicContext.subContext(); + ValidationEventListener listener = getListener(); for (ILet let : lets) { IEnhancedQName name = let.getName(); - ISequence result = let.getValueExpression().evaluate(focus, subContext); - subContext.bindVariableValue( - name, - // ensure the sequence is list backed - result.reusable()); + listener.beforeLetEvaluation(let); + try { + ISequence result = let.getValueExpression().evaluate(focus, subContext); + subContext.bindVariableValue( + name, + // ensure the sequence is list backed + result.reusable()); + } finally { + listener.afterLetEvaluation(let); + } } retval = subContext; } @@ -1217,7 +1261,7 @@ public Void visitAssembly(@NonNull IAssemblyNodeItem item, DynamicContext contex } // Parallel or sequential child traversal - if (parallelConfig.isParallel() && shouldParallelize(item)) { + if (validationConfig.isParallel() && shouldParallelize(item)) { visitFlags(item, effectiveContext); visitChildrenParallel(item, effectiveContext); } else { @@ -1250,7 +1294,7 @@ private void visitChildrenParallel( @NonNull IAssemblyNodeItem item, @NonNull DynamicContext context) { - ExecutorService executor = parallelConfig.getExecutor(); + ExecutorService executor = validationConfig.getExecutor(); List> children = item.modelItems() .collect(Collectors.toList()); diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/IConstraint.java b/core/src/main/java/dev/metaschema/core/model/constraint/IConstraint.java index 80a5ecaae3..d4a36fac0a 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/IConstraint.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/IConstraint.java @@ -138,6 +138,29 @@ static String getConstraintIdentity(@NonNull IConstraint constraint) { return ObjectUtils.notNull(identity); } + /** + * Get a stable identifier for this constraint, suitable for use in SARIF output + * and timing correlation. + *

+ * Returns the author-defined {@link #getId()} if present. Otherwise, generates + * a deterministic fallback identifier based on the constraint type, source + * location, and target expression. + * + * @return a non-null identifier string + */ + @NonNull + default String getInternalIdentifier() { + String id = getId(); + if (id != null) { + return id; + } + // Deterministic fallback based on constraint properties + String source = getSource().getLocationHint(); + String target = getTarget().getPath(); + int hash = (source + "|" + target).hashCode(); + return ObjectUtils.notNull(getType().getName() + "-" + String.format("%08x", hash)); + } + /** * Get the constraint type. * diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/ILet.java b/core/src/main/java/dev/metaschema/core/model/constraint/ILet.java index 88d9d25200..c592224a84 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/ILet.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/ILet.java @@ -10,6 +10,7 @@ import dev.metaschema.core.model.ISource; import dev.metaschema.core.model.constraint.impl.DefaultLet; import dev.metaschema.core.qname.IEnhancedQName; +import dev.metaschema.core.util.ObjectUtils; import edu.umd.cs.findbugs.annotations.NonNull; import edu.umd.cs.findbugs.annotations.Nullable; @@ -71,6 +72,24 @@ static ILet of( return new DefaultLet(name, valueExpression, source, remarks); } + /** + * Get a stable identifier for this let statement, suitable for use in SARIF + * output and timing correlation. + *

+ * Generates a deterministic identifier based on the variable name, source + * location, and value expression. + * + * @return a non-null identifier string + */ + @NonNull + default String getInternalIdentifier() { + String localName = getName().getLocalName(); + String source = getSource().getLocationHint(); + String expression = getValueExpression().getPath(); + int hash = (source + "|" + expression).hashCode(); + return ObjectUtils.notNull("let-" + localName + "-" + String.format("%08x", hash)); + } + /** * Get the name of the let variable. * diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/NoOpValidationEventListener.java b/core/src/main/java/dev/metaschema/core/model/constraint/NoOpValidationEventListener.java new file mode 100644 index 0000000000..04f78b1638 --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/NoOpValidationEventListener.java @@ -0,0 +1,63 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import java.net.URI; + +import dev.metaschema.core.metapath.item.node.INodeItem; + +/** + * A no-op implementation of {@link ValidationEventListener} that ignores all + * events. + *

+ * This is the default listener used by {@link ValidationConfig} when no + * instrumentation is configured, ensuring zero overhead in the common case. + */ +public class NoOpValidationEventListener implements ValidationEventListener { + + /** Singleton instance. */ + public static final NoOpValidationEventListener INSTANCE = new NoOpValidationEventListener(); + + @Override + public void beforeValidation(URI document) { + // no-op + } + + @Override + public void afterValidation(URI document) { + // no-op + } + + @Override + public void beforePhase(ValidationPhase phase) { + // no-op + } + + @Override + public void afterPhase(ValidationPhase phase) { + // no-op + } + + @Override + public void beforeConstraintEvaluation(IConstraint constraint, INodeItem target) { + // no-op + } + + @Override + public void afterConstraintEvaluation(IConstraint constraint, INodeItem target) { + // no-op + } + + @Override + public void beforeLetEvaluation(ILet let) { + // no-op + } + + @Override + public void afterLetEvaluation(ILet let) { + // no-op + } +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/TimingCollector.java b/core/src/main/java/dev/metaschema/core/model/constraint/TimingCollector.java new file mode 100644 index 0000000000..e64adce845 --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/TimingCollector.java @@ -0,0 +1,232 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import java.net.URI; +import java.time.Instant; +import java.util.ArrayDeque; +import java.util.Collections; +import java.util.Deque; +import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; + +import dev.metaschema.core.metapath.item.node.INodeItem; +import edu.umd.cs.findbugs.annotations.NonNull; +import edu.umd.cs.findbugs.annotations.Nullable; + +/** + * A {@link ValidationEventListener} implementation that collects timing + * measurements for all validation events. + *

+ * Timing data is organized hierarchically: + *

    + *
  • Overall validation timing
    • + *
  • Per-phase timing (keyed by {@link ValidationPhase})
    • + *
  • Per-constraint timing (keyed by + * {@link IConstraint#getInternalIdentifier()})
    • + *
  • Per-let-statement timing (keyed by + * {@link ILet#getInternalIdentifier()})
    • + *
+ *

+ * This class is thread-safe. Each thread maintains its own stack of start times + * to handle nested events correctly (e.g., a constraint evaluation that + * triggers let-statement evaluations). + * + * @see TimingRecord + * @see ValidationEventListener + */ +public class TimingCollector implements ValidationEventListener { + @NonNull + private final ConcurrentHashMap phaseTimings = new ConcurrentHashMap<>(); + @NonNull + private final ConcurrentHashMap constraintTimings = new ConcurrentHashMap<>(); + @NonNull + private final ConcurrentHashMap letTimings = new ConcurrentHashMap<>(); + @SuppressWarnings("PMD.AvoidUsingVolatile") // Required for thread-safe publication + @Nullable + private volatile TimingRecord validationTiming; + + /** + * Thread-local stacks of nano-time start values, used to support nested + * before/after event pairs. + */ + @NonNull + private final ThreadLocal> startTimeStack = ThreadLocal.withInitial(ArrayDeque::new); + + /** + * Construct a new, empty timing collector. + */ + public TimingCollector() { + // nothing to initialize beyond field defaults + } + + /** + * Push a start time onto the current thread's stack. + */ + private void pushStartTime() { + startTimeStack.get().push(System.nanoTime()); + } + + /** + * Pop and return the most recent start time from the current thread's stack. + * + * @return the elapsed duration in nanoseconds since the corresponding push + */ + private long popElapsedNs() { + Long startNs = startTimeStack.get().poll(); + if (startNs == null) { + return 0L; + } + return System.nanoTime() - startNs; + } + + @Override + public void beforeValidation(@NonNull URI document) { + TimingRecord record = validationTiming; + if (record == null) { + record = new TimingRecord(); + validationTiming = record; + } + record.recordStart(Instant.now()); + pushStartTime(); + } + + @Override + public void afterValidation(@NonNull URI document) { + long elapsed = popElapsedNs(); + TimingRecord record = validationTiming; + if (record != null) { + record.recordEnd(elapsed, Instant.now()); + } + } + + @Override + public void beforePhase(@NonNull ValidationPhase phase) { + phaseTimings.computeIfAbsent(phase, k -> new TimingRecord()) + .recordStart(Instant.now()); + pushStartTime(); + } + + @Override + public void afterPhase(@NonNull ValidationPhase phase) { + long elapsed = popElapsedNs(); + TimingRecord record = phaseTimings.get(phase); + if (record != null) { + record.recordEnd(elapsed, Instant.now()); + } + } + + @Override + public void beforeConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + String id = constraint.getInternalIdentifier(); + constraintTimings.computeIfAbsent(id, k -> new TimingRecord()) + .recordStart(Instant.now()); + pushStartTime(); + } + + @Override + public void afterConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + long elapsed = popElapsedNs(); + String id = constraint.getInternalIdentifier(); + TimingRecord record = constraintTimings.get(id); + if (record != null) { + record.recordEnd(elapsed, Instant.now()); + } + } + + @Override + public void beforeLetEvaluation(@NonNull ILet let) { + letTimings.computeIfAbsent(let, k -> new TimingRecord()) + .recordStart(Instant.now()); + pushStartTime(); + } + + @Override + public void afterLetEvaluation(@NonNull ILet let) { + long elapsed = popElapsedNs(); + TimingRecord record = letTimings.get(let); + if (record != null) { + record.recordEnd(elapsed, Instant.now()); + } + } + + /** + * Get the timing record for a specific validation phase. + * + * @param phase + * the phase to look up + * @return the timing record, or {@code null} if the phase was not recorded + */ + @Nullable + public TimingRecord getPhaseTiming(@NonNull ValidationPhase phase) { + return phaseTimings.get(phase); + } + + /** + * Get all phase timing records. + * + * @return an unmodifiable map of phase to timing record + */ + @NonNull + public Map getPhaseTimings() { + return Collections.unmodifiableMap(phaseTimings); + } + + /** + * Get the timing record for a specific constraint by its internal identifier. + * + * @param constraintId + * the constraint's internal identifier + * @return the timing record, or {@code null} if the constraint was not recorded + */ + @Nullable + public TimingRecord getConstraintTiming(@NonNull String constraintId) { + return constraintTimings.get(constraintId); + } + + /** + * Get all constraint timing records. + * + * @return an unmodifiable map of constraint identifier to timing record + */ + @NonNull + public Map getConstraintTimings() { + return Collections.unmodifiableMap(constraintTimings); + } + + /** + * Get the timing record for a specific let-statement. + * + * @param let + * the let-statement to look up + * @return the timing record, or {@code null} if the let was not recorded + */ + @Nullable + public TimingRecord getLetTiming(@NonNull ILet let) { + return letTimings.get(let); + } + + /** + * Get all let-statement timing records. + * + * @return an unmodifiable map of let-statement to timing record + */ + @NonNull + public Map getLetTimings() { + return Collections.unmodifiableMap(letTimings); + } + + /** + * Get the overall validation timing record. + * + * @return the validation timing record, or {@code null} if validation was not + * recorded + */ + @Nullable + public TimingRecord getValidationTiming() { + return validationTiming; + } +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/TimingRecord.java b/core/src/main/java/dev/metaschema/core/model/constraint/TimingRecord.java new file mode 100644 index 0000000000..b9c701c66e --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/TimingRecord.java @@ -0,0 +1,144 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import java.time.Instant; +import java.util.concurrent.atomic.AtomicLong; +import java.util.concurrent.atomic.AtomicReference; +import java.util.concurrent.atomic.LongAdder; + +import edu.umd.cs.findbugs.annotations.NonNull; +import edu.umd.cs.findbugs.annotations.Nullable; + +/** + * Thread-safe accumulator for timing measurements of a single timed entity + * (constraint, let-statement, phase, or overall validation). + *

+ * Records total elapsed time, invocation count, and min/max per-invocation + * durations. Also tracks the wall-clock start and end timestamps in UTC. + *

+ * All methods are safe to call from multiple threads concurrently. + */ +public class TimingRecord { + @NonNull + private final LongAdder totalTimeNs = new LongAdder(); + @NonNull + private final LongAdder count = new LongAdder(); + @NonNull + private final AtomicLong minTimeNs = new AtomicLong(Long.MAX_VALUE); + @NonNull + private final AtomicLong maxTimeNs = new AtomicLong(Long.MIN_VALUE); + @NonNull + private final AtomicReference startTimestampUtc = new AtomicReference<>(); + @NonNull + private final AtomicReference endTimestampUtc = new AtomicReference<>(); + + /** + * Record the start of a timed event. Atomically keeps the earliest start + * timestamp across all invocations. + * + * @param startTimestamp + * the wall-clock time when the event began + */ + void recordStart(@NonNull Instant startTimestamp) { + startTimestampUtc.accumulateAndGet( + startTimestamp, + (prev, next) -> prev == null || next.isBefore(prev) ? next : prev); + } + + /** + * Record the completion of a timed event. Atomically keeps the latest end + * timestamp across all invocations. + * + * @param durationNs + * the elapsed time of this invocation in nanoseconds + * @param endTimestamp + * the wall-clock time when the event completed + */ + void recordEnd(long durationNs, @NonNull Instant endTimestamp) { + totalTimeNs.add(durationNs); + count.increment(); + endTimestampUtc.accumulateAndGet( + endTimestamp, + (prev, next) -> prev == null || next.isAfter(prev) ? next : prev); + + // update min atomically + long currentMin; + do { + currentMin = minTimeNs.get(); + if (durationNs >= currentMin) { + break; + } + } while (!minTimeNs.compareAndSet(currentMin, durationNs)); + + // update max atomically + long currentMax; + do { + currentMax = maxTimeNs.get(); + if (durationNs <= currentMax) { + break; + } + } while (!maxTimeNs.compareAndSet(currentMax, durationNs)); + } + + /** + * Get the total accumulated time across all invocations. + * + * @return total time in nanoseconds + */ + public long getTotalTimeNs() { + return totalTimeNs.sum(); + } + + /** + * Get the number of times this entity has been timed. + * + * @return the invocation count + */ + public long getCount() { + return count.sum(); + } + + /** + * Get the minimum single-invocation duration recorded. + * + * @return minimum time in nanoseconds, or {@link Long#MAX_VALUE} if no + * invocations have been recorded + */ + public long getMinTimeNs() { + return minTimeNs.get(); + } + + /** + * Get the maximum single-invocation duration recorded. + * + * @return maximum time in nanoseconds, or {@link Long#MIN_VALUE} if no + * invocations have been recorded + */ + public long getMaxTimeNs() { + return maxTimeNs.get(); + } + + /** + * Get the wall-clock timestamp of the earliest recorded start event. + * + * @return the start timestamp, or {@code null} if no events have been recorded + */ + @Nullable + public Instant getStartTimestampUtc() { + return startTimestampUtc.get(); + } + + /** + * Get the wall-clock timestamp of the latest recorded end event. + * + * @return the end timestamp, or {@code null} if no events have completed + */ + @Nullable + public Instant getEndTimestampUtc() { + return endTimestampUtc.get(); + } +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/ParallelValidationConfig.java b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationConfig.java similarity index 55% rename from core/src/main/java/dev/metaschema/core/model/constraint/ParallelValidationConfig.java rename to core/src/main/java/dev/metaschema/core/model/constraint/ValidationConfig.java index 25a2bbea24..afd83b80f8 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/ParallelValidationConfig.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationConfig.java @@ -7,6 +7,7 @@ import org.eclipse.jdt.annotation.Owning; +import java.util.List; import java.util.Objects; import java.util.concurrent.ExecutorService; import java.util.concurrent.ForkJoinPool; @@ -16,9 +17,10 @@ import edu.umd.cs.findbugs.annotations.Nullable; /** - * Configuration for parallel constraint validation. + * Configuration for constraint validation. *

- * This class supports two modes: + * This class supports parallel execution and optional event-based + * instrumentation. Two execution modes are available: *

    *
  • Internal thread pool: Created via {@link #withThreads(int)}, shut down by * {@link #close()}. Uses {@link ForkJoinPool} internally to handle nested @@ -27,10 +29,15 @@ * NOT shut down by {@link #close()}
    • *
*

+ * An optional {@link ValidationEventListener} can be configured via + * {@link #withListener(ValidationEventListener)} to receive callbacks during + * validation. By default, a {@link NoOpValidationEventListener} is used, + * ensuring zero overhead when instrumentation is not needed. + *

* Instances should be used with try-with-resources or explicitly closed after * validation. */ -public final class ParallelValidationConfig implements AutoCloseable { +public final class ValidationConfig implements AutoCloseable { /** * Single-threaded sequential execution (default, current behavior). @@ -39,7 +46,8 @@ public final class ParallelValidationConfig implements AutoCloseable { */ @SuppressWarnings("resource") @NonNull - public static final ParallelValidationConfig SEQUENTIAL = new ParallelValidationConfig(null, 1, false); + public static final ValidationConfig SEQUENTIAL = new ValidationConfig(null, 1, false, + NoOpValidationEventListener.INSTANCE); /** * The executor service, lazily initialized if using internal pool. @@ -51,11 +59,18 @@ public final class ParallelValidationConfig implements AutoCloseable { private volatile ExecutorService executor; private final int threadCount; private final boolean ownsExecutor; + @NonNull + private final ValidationEventListener listener; - private ParallelValidationConfig(@Nullable ExecutorService executor, int threadCount, boolean ownsExecutor) { + private ValidationConfig( + @Nullable ExecutorService executor, + int threadCount, + boolean ownsExecutor, + @NonNull ValidationEventListener listener) { this.executor = executor; this.threadCount = threadCount; this.ownsExecutor = ownsExecutor; + this.listener = listener; } /** @@ -74,9 +89,9 @@ private ParallelValidationConfig(@Nullable ExecutorService executor, int threadC */ @NonNull @Owning - public static ParallelValidationConfig withExecutor(@NonNull ExecutorService executor) { + public static ValidationConfig withExecutor(@NonNull ExecutorService executor) { Objects.requireNonNull(executor, "executor must not be null"); - return new ParallelValidationConfig(executor, 0, false); + return new ValidationConfig(executor, 0, false, NoOpValidationEventListener.INSTANCE); } /** @@ -94,14 +109,65 @@ public static ParallelValidationConfig withExecutor(@NonNull ExecutorService exe */ @NonNull @Owning - public static ParallelValidationConfig withThreads(int threadCount) { + public static ValidationConfig withThreads(int threadCount) { if (threadCount < 1) { throw new IllegalArgumentException("threadCount must be at least 1, got: " + threadCount); } if (threadCount == 1) { return SEQUENTIAL; } - return new ParallelValidationConfig(null, threadCount, true); + return new ValidationConfig(null, threadCount, true, NoOpValidationEventListener.INSTANCE); + } + + /** + * Create a new configuration with the specified event listener, preserving the + * current parallel execution settings. + *

+ * If this config owns its executor, the derived config will lazily create its + * own independent pool to avoid unsafe sharing of owned executors. + * + * @param listener + * the event listener to use for validation instrumentation + * @return a new configuration with the given listener + * @throws NullPointerException + * if listener is null + */ + @NonNull + @Owning + public ValidationConfig withListener(@NonNull ValidationEventListener listener) { + Objects.requireNonNull(listener, "listener must not be null"); + if (this.ownsExecutor) { + // Don't share owned executor; derived config will lazily create its own + return new ValidationConfig(null, this.threadCount, true, listener); + } + return new ValidationConfig(this.executor, this.threadCount, false, listener); + } + + /** + * Create a new configuration that adds an additional event listener, preserving + * the current parallel execution settings and any existing listener. + *

+ * If the current listener is a {@link NoOpValidationEventListener}, the new + * listener replaces it directly. Otherwise, a + * {@link CompositeValidationEventListener} is created to deliver events to both + * the existing and new listeners. + * + * @param additionalListener + * the additional event listener to add + * @return a new configuration with the additional listener + * @throws NullPointerException + * if additionalListener is null + */ + @NonNull + @Owning + public ValidationConfig addListener(@NonNull ValidationEventListener additionalListener) { + Objects.requireNonNull(additionalListener, "additionalListener must not be null"); + ValidationEventListener current = this.listener; + if (current instanceof NoOpValidationEventListener) { + return withListener(additionalListener); + } + return withListener( + new CompositeValidationEventListener(List.of(current, additionalListener))); } /** @@ -113,6 +179,16 @@ public boolean isParallel() { return executor != null || threadCount > 1; } + /** + * Get the configured validation event listener. + * + * @return the event listener, never null + */ + @NonNull + public ValidationEventListener getListener() { + return listener; + } + /** * Get the executor service, creating an internal pool if needed. *

diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/ValidationEventListener.java b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationEventListener.java new file mode 100644 index 0000000000..a278821999 --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationEventListener.java @@ -0,0 +1,96 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import java.net.URI; + +import dev.metaschema.core.metapath.item.node.INodeItem; +import edu.umd.cs.findbugs.annotations.NonNull; + +/** + * Listener interface for validation pipeline events. + *

+ * Implementations receive callbacks at four granularity levels: overall + * validation, phase, individual constraint evaluation, and let-statement + * evaluation. This enables instrumentation such as timing collection without + * coupling measurement logic to the validation code. + *

+ * A no-op implementation is provided by {@link NoOpValidationEventListener} for + * use when instrumentation is not needed. + * + * @see NoOpValidationEventListener + * @see ValidationPhase + */ +public interface ValidationEventListener { + + /** + * Called before validation of a document begins. + * + * @param document + * the URI of the document being validated + */ + void beforeValidation(@NonNull URI document); + + /** + * Called after validation of a document completes. + * + * @param document + * the URI of the document that was validated + */ + void afterValidation(@NonNull URI document); + + /** + * Called before a validation phase begins. + * + * @param phase + * the phase about to start + */ + void beforePhase(@NonNull ValidationPhase phase); + + /** + * Called after a validation phase completes. + * + * @param phase + * the phase that completed + */ + void afterPhase(@NonNull ValidationPhase phase); + + /** + * Called before a single constraint is evaluated against a target node. + * + * @param constraint + * the constraint being evaluated + * @param target + * the node item the constraint is evaluated against + */ + void beforeConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target); + + /** + * Called after a single constraint evaluation completes. + * + * @param constraint + * the constraint that was evaluated + * @param target + * the node item the constraint was evaluated against + */ + void afterConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target); + + /** + * Called before a let-statement variable binding is evaluated. + * + * @param let + * the let expression being evaluated + */ + void beforeLetEvaluation(@NonNull ILet let); + + /** + * Called after a let-statement variable binding evaluation completes. + * + * @param let + * the let expression that was evaluated + */ + void afterLetEvaluation(@NonNull ILet let); +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/ValidationFeature.java b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationFeature.java index 0b428f9719..f4bf747f77 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/ValidationFeature.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationFeature.java @@ -41,6 +41,20 @@ public final class ValidationFeature @NonNull public static final ValidationFeature PARALLEL_THREADS = new ValidationFeature<>("parallel-threads", Integer.class, 1); + /** + * An optional event listener to receive callbacks during constraint validation. + *

+ * This allows external instrumentation (e.g., timing collection) to observe + * validation events without modifying the validator itself. The default is a + * no-op listener with zero overhead. + * + * @see TimingCollector + * @see ValidationEventListener + */ + @NonNull + public static final ValidationFeature EVENT_LISTENER + = new ValidationFeature<>("event-listener", ValidationEventListener.class, + NoOpValidationEventListener.INSTANCE); private ValidationFeature( @NonNull String name, diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/ValidationPhase.java b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationPhase.java new file mode 100644 index 0000000000..365649cf98 --- /dev/null +++ b/core/src/main/java/dev/metaschema/core/model/constraint/ValidationPhase.java @@ -0,0 +1,20 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +/** + * Represents the distinct phases of the validation pipeline. + *

+ * Used by {@link ValidationEventListener} to report phase-level timing events. + */ +public enum ValidationPhase { + /** Schema validation against XML or JSON schema. */ + SCHEMA_VALIDATION, + /** Constraint evaluation against Metaschema constraints. */ + CONSTRAINT_VALIDATION, + /** Post-validation finalization, including cross-document constraints. */ + FINALIZATION +} diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/impl/AbstractConstraint.java b/core/src/main/java/dev/metaschema/core/model/constraint/impl/AbstractConstraint.java index 51179842f1..1ba2a48992 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/impl/AbstractConstraint.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/impl/AbstractConstraint.java @@ -27,6 +27,9 @@ * The base class for all constraint implementations. */ public abstract class AbstractConstraint implements IConstraint { // NOPMD - intentional data class + @SuppressWarnings("PMD.AvoidUsingVolatile") // Required for thread-safe lazy init + @Nullable + private volatile String cachedIdentifier; @Nullable private final String id; @Nullable @@ -90,6 +93,16 @@ public final String getId() { return id; } + @Override + public String getInternalIdentifier() { + String result = cachedIdentifier; + if (result == null) { + result = IConstraint.super.getInternalIdentifier(); + cachedIdentifier = result; + } + return result; + } + @Override public MarkupLine getDescription() { return description; diff --git a/core/src/main/java/dev/metaschema/core/model/constraint/impl/DefaultLet.java b/core/src/main/java/dev/metaschema/core/model/constraint/impl/DefaultLet.java index 976ac2e11d..db36209d42 100644 --- a/core/src/main/java/dev/metaschema/core/model/constraint/impl/DefaultLet.java +++ b/core/src/main/java/dev/metaschema/core/model/constraint/impl/DefaultLet.java @@ -20,6 +20,9 @@ */ @SuppressWarnings("PMD.DataClass") public class DefaultLet implements ILet { + @SuppressWarnings("PMD.AvoidUsingVolatile") // Required for thread-safe lazy init + @Nullable + private volatile String cachedIdentifier; @NonNull private final IEnhancedQName name; @NonNull @@ -52,6 +55,16 @@ public DefaultLet( this.remarks = remarks; } + @Override + public String getInternalIdentifier() { + String result = cachedIdentifier; + if (result == null) { + result = ILet.super.getInternalIdentifier(); + cachedIdentifier = result; + } + return result; + } + @Override public IEnhancedQName getName() { return name; diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/CompositeValidationEventListenerTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/CompositeValidationEventListenerTest.java new file mode 100644 index 0000000000..8c1fe1672a --- /dev/null +++ b/core/src/test/java/dev/metaschema/core/model/constraint/CompositeValidationEventListenerTest.java @@ -0,0 +1,105 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import static org.junit.jupiter.api.Assertions.assertDoesNotThrow; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.verify; + +import org.junit.jupiter.api.Test; + +import java.net.URI; +import java.util.Collections; +import java.util.List; + +import dev.metaschema.core.metapath.IMetapathExpression; +import dev.metaschema.core.metapath.item.node.INodeItem; +import dev.metaschema.core.model.ISource; +import dev.metaschema.core.qname.IEnhancedQName; + +@SuppressWarnings("PMD.TooManyStaticImports") +class CompositeValidationEventListenerTest { + + @Test + void testDelegatesToAllListeners() { + ValidationEventListener listener1 = mock(ValidationEventListener.class); + ValidationEventListener listener2 = mock(ValidationEventListener.class); + + CompositeValidationEventListener composite + = new CompositeValidationEventListener(List.of(listener1, listener2)); + + URI doc = URI.create("https://example.com/doc.xml"); + INodeItem target = mock(INodeItem.class); + IConstraint constraint = mock(IConstraint.class); + ILet let = ILet.of( + IEnhancedQName.of("test-var"), + IMetapathExpression.compile("1"), + ISource.externalSource("https://example.com/module"), + null); + + // Fire all event types + composite.beforeValidation(doc); + composite.afterValidation(doc); + composite.beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + composite.afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + composite.beforeConstraintEvaluation(constraint, target); + composite.afterConstraintEvaluation(constraint, target); + composite.beforeLetEvaluation(let); + composite.afterLetEvaluation(let); + + // Verify both listeners received all events + verify(listener1).beforeValidation(doc); + verify(listener1).afterValidation(doc); + verify(listener1).beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + verify(listener1).afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + verify(listener1).beforeConstraintEvaluation(constraint, target); + verify(listener1).afterConstraintEvaluation(constraint, target); + verify(listener1).beforeLetEvaluation(let); + verify(listener1).afterLetEvaluation(let); + + verify(listener2).beforeValidation(doc); + verify(listener2).afterValidation(doc); + verify(listener2).beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + verify(listener2).afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + verify(listener2).beforeConstraintEvaluation(constraint, target); + verify(listener2).afterConstraintEvaluation(constraint, target); + verify(listener2).beforeLetEvaluation(let); + verify(listener2).afterLetEvaluation(let); + } + + @Test + void testEmptyListenerList() { + CompositeValidationEventListener composite + = new CompositeValidationEventListener(Collections.emptyList()); + + URI doc = URI.create("https://example.com/doc.xml"); + INodeItem target = mock(INodeItem.class); + IConstraint constraint = mock(IConstraint.class); + + // Should not throw with empty listener list + assertDoesNotThrow(() -> { + composite.beforeValidation(doc); + composite.afterValidation(doc); + composite.beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + composite.afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + composite.beforeConstraintEvaluation(constraint, target); + composite.afterConstraintEvaluation(constraint, target); + }); + } + + @Test + void testSingleListener() { + ValidationEventListener listener = mock(ValidationEventListener.class); + + CompositeValidationEventListener composite + = new CompositeValidationEventListener(List.of(listener)); + + URI doc = URI.create("https://example.com/doc.xml"); + composite.beforeValidation(doc); + + verify(listener).beforeValidation(doc); + } +} diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/ConstraintIdentifierTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/ConstraintIdentifierTest.java new file mode 100644 index 0000000000..a2328fb872 --- /dev/null +++ b/core/src/test/java/dev/metaschema/core/model/constraint/ConstraintIdentifierTest.java @@ -0,0 +1,156 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import org.junit.jupiter.api.Test; + +import java.net.URI; + +import dev.metaschema.core.metapath.IMetapathExpression; +import dev.metaschema.core.metapath.StaticContext; +import dev.metaschema.core.model.ISource; +import dev.metaschema.core.qname.IEnhancedQName; + +/** + * Tests for constraint and let-statement identifier generation. + */ +class ConstraintIdentifierTest { + + @Test + void testConstraintWithExplicitIdUsesIt() { + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("my-explicit-id") + .test(IMetapathExpression.compile("true()")) + .build(); + + assertEquals("my-explicit-id", constraint.getInternalIdentifier()); + } + + @Test + void testConstraintWithoutIdGetsDeterministicFallback() { + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .test(IMetapathExpression.compile("string-length(.) > 0")) + .build(); + + String identifier = constraint.getInternalIdentifier(); + assertNotNull(identifier); + assertTrue(identifier.startsWith("expect-"), + "fallback identifier should start with constraint type name, got: " + identifier); + } + + @Test + void testConstraintIdentifierIsCached() { + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("cached-id") + .test(IMetapathExpression.compile("true()")) + .build(); + + String first = constraint.getInternalIdentifier(); + String second = constraint.getInternalIdentifier(); + assertSame(first, second, "repeated calls should return the same cached instance"); + } + + @Test + void testConstraintFallbackIsDeterministicAcrossCalls() { + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .test(IMetapathExpression.compile("string-length(.) > 0")) + .build(); + + String first = constraint.getInternalIdentifier(); + String second = constraint.getInternalIdentifier(); + assertEquals(first, second, "fallback identifier should be deterministic"); + } + + @Test + void testDifferentConstraintTypesGetDifferentPrefixes() { + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint expect = IExpectConstraint.builder() + .source(source) + .test(IMetapathExpression.compile("true()")) + .build(); + + StaticContext staticContext = StaticContext.builder() + .baseUri(URI.create("https://example.com/module")) + .build(); + + IMatchesConstraint matches = IMatchesConstraint.builder() + .source(ISource.externalSource(staticContext, false)) + .regex(".*") + .build(); + + assertTrue(expect.getInternalIdentifier().startsWith("expect-"), + "expect constraint identifier should start with 'expect-'"); + assertTrue(matches.getInternalIdentifier().startsWith("matches-"), + "matches constraint identifier should start with 'matches-'"); + } + + @Test + void testLetIdentifierFormat() { + ISource source = ISource.externalSource("https://example.com/module"); + IEnhancedQName name = IEnhancedQName.of("my-variable"); + + ILet let = ILet.of( + name, + IMetapathExpression.compile("count(//item)"), + source, + null); + + String identifier = let.getInternalIdentifier(); + assertNotNull(identifier); + assertTrue(identifier.startsWith("let-my-variable"), + "let identifier should start with 'let-{name}', got: " + identifier); + } + + @Test + void testLetIdentifierIsCached() { + ISource source = ISource.externalSource("https://example.com/module"); + IEnhancedQName name = IEnhancedQName.of("cached-var"); + + ILet let = ILet.of( + name, + IMetapathExpression.compile("true()"), + source, + null); + + String first = let.getInternalIdentifier(); + String second = let.getInternalIdentifier(); + assertSame(first, second, "repeated calls should return the same cached instance"); + } + + @Test + void testLetIdentifierIsDeterministic() { + ISource source = ISource.externalSource("https://example.com/module"); + IEnhancedQName name = IEnhancedQName.of("det-var"); + + ILet let = ILet.of( + name, + IMetapathExpression.compile("count(//item)"), + source, + null); + + String first = let.getInternalIdentifier(); + String second = let.getInternalIdentifier(); + assertEquals(first, second, "let identifier should be deterministic"); + } +} diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/DefaultConstraintValidatorThreadSafetyTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/DefaultConstraintValidatorThreadSafetyTest.java index b72307e273..e6b3d7ba1d 100644 --- a/core/src/test/java/dev/metaschema/core/model/constraint/DefaultConstraintValidatorThreadSafetyTest.java +++ b/core/src/test/java/dev/metaschema/core/model/constraint/DefaultConstraintValidatorThreadSafetyTest.java @@ -44,14 +44,14 @@ void testParallelValidationBehavioralEquivalence() throws Exception { // Run validation with sequential config FindingCollectingConstraintValidationHandler sequentialHandler = new FindingCollectingConstraintValidationHandler(); try (DefaultConstraintValidator sequentialValidator - = new DefaultConstraintValidator(sequentialHandler, ParallelValidationConfig.SEQUENTIAL)) { + = new DefaultConstraintValidator(sequentialHandler, ValidationConfig.SEQUENTIAL)) { runValidationOperations(sequentialValidator); } int sequentialFindingCount = sequentialHandler.getFindings().size(); // Run validation with parallel config FindingCollectingConstraintValidationHandler parallelHandler = new FindingCollectingConstraintValidationHandler(); - try (ParallelValidationConfig config = ParallelValidationConfig.withThreads(4)) { + try (ValidationConfig config = ValidationConfig.withThreads(4)) { assertTrue(config.isParallel(), "Config should be parallel with 4 threads"); try (DefaultConstraintValidator parallelValidator = new DefaultConstraintValidator(parallelHandler, config)) { @@ -116,7 +116,7 @@ void testSequentialValidationBackwardCompatibility() { // New constructor with SEQUENTIAL config should also work try (DefaultConstraintValidator validator - = new DefaultConstraintValidator(handler, ParallelValidationConfig.SEQUENTIAL)) { + = new DefaultConstraintValidator(handler, ValidationConfig.SEQUENTIAL)) { assertNotNull(validator, "New constructor with SEQUENTIAL should work"); } } diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/ParallelValidationConfigTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/ParallelValidationConfigTest.java deleted file mode 100644 index 1a2e5a02ab..0000000000 --- a/core/src/test/java/dev/metaschema/core/model/constraint/ParallelValidationConfigTest.java +++ /dev/null @@ -1,88 +0,0 @@ -/* - * SPDX-FileCopyrightText: none - * SPDX-License-Identifier: CC0-1.0 - */ - -package dev.metaschema.core.model.constraint; - -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertThrows; -import static org.junit.jupiter.api.Assertions.assertTrue; - -import org.junit.jupiter.api.Test; - -import java.util.concurrent.ExecutorService; -import java.util.concurrent.Executors; - -import dev.metaschema.core.util.ObjectUtils; - -class ParallelValidationConfigTest { - - @Test - void testSequentialIsNotParallel() { - ParallelValidationConfig config = ParallelValidationConfig.SEQUENTIAL; - assertFalse(config.isParallel()); - } - - @Test - void testWithThreadsOneIsNotParallel() { - try (ParallelValidationConfig config = ParallelValidationConfig.withThreads(1)) { - assertFalse(config.isParallel()); - } - } - - @Test - void testWithThreadsFourIsParallel() { - try (ParallelValidationConfig config = ParallelValidationConfig.withThreads(4)) { - assertTrue(config.isParallel()); - config.close(); - } - } - - @Test - void testWithThreadsZeroThrows() { - assertThrows(IllegalArgumentException.class, () -> ParallelValidationConfig.withThreads(0)); - } - - @Test - void testWithThreadsNegativeThrows() { - assertThrows(IllegalArgumentException.class, () -> ParallelValidationConfig.withThreads(-1)); - } - - @Test - void testWithExecutorIsParallel() { - ExecutorService executor = ObjectUtils.notNull(Executors.newFixedThreadPool(2)); - try (ParallelValidationConfig config = ParallelValidationConfig.withExecutor(executor)) { - assertTrue(config.isParallel()); - } finally { - executor.shutdown(); - } - } - - @SuppressWarnings("null") - @Test - void testWithExecutorNullThrows() { - assertThrows(NullPointerException.class, () -> ParallelValidationConfig.withExecutor(null)); - } - - @Test - void testCloseShutdownsInternalExecutor() { - try (ParallelValidationConfig config = ParallelValidationConfig.withThreads(2)) { - ExecutorService executor = config.getExecutor(); - assertFalse(executor.isShutdown()); - config.close(); - assertTrue(executor.isShutdown()); - } - } - - @Test - void testCloseDoesNotShutdownExternalExecutor() { - ExecutorService executor = ObjectUtils.notNull(Executors.newFixedThreadPool(2)); - try (ParallelValidationConfig config = ParallelValidationConfig.withExecutor(executor)) { - config.close(); - assertFalse(executor.isShutdown()); - } finally { - executor.shutdown(); - } - } -} diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorTest.java new file mode 100644 index 0000000000..7571b35d83 --- /dev/null +++ b/core/src/test/java/dev/metaschema/core/model/constraint/TimingCollectorTest.java @@ -0,0 +1,297 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.Mockito.mock; + +import org.junit.jupiter.api.Test; + +import java.net.URI; +import java.util.Map; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; + +import dev.metaschema.core.metapath.IMetapathExpression; +import dev.metaschema.core.metapath.item.node.INodeItem; +import dev.metaschema.core.model.ISource; +import dev.metaschema.core.qname.IEnhancedQName; +import dev.metaschema.core.util.ObjectUtils; + +/** + * Tests for {@link TimingCollector} and {@link TimingRecord}. + */ +@SuppressWarnings("PMD.TooManyStaticImports") +class TimingCollectorTest { + + @Test + void testPhaseTimingAccumulation() { + TimingCollector collector = new TimingCollector(); + + collector.beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + // simulate some work + collector.afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + + TimingRecord record = collector.getPhaseTiming(ValidationPhase.CONSTRAINT_VALIDATION); + assertNotNull(record, "phase timing record should exist"); + assertEquals(1, record.getCount()); + assertTrue(record.getTotalTimeNs() >= 0); + assertNotNull(record.getStartTimestampUtc()); + assertNotNull(record.getEndTimestampUtc()); + } + + @Test + void testConstraintTimingAccumulation() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("test-constraint") + .test(IMetapathExpression.compile("true()")) + .build(); + + INodeItem target = mock(INodeItem.class); + + collector.beforeConstraintEvaluation(constraint, target); + collector.afterConstraintEvaluation(constraint, target); + + TimingRecord record = collector.getConstraintTiming("test-constraint"); + assertNotNull(record, "constraint timing record should exist"); + assertEquals(1, record.getCount()); + assertTrue(record.getTotalTimeNs() >= 0); + } + + @Test + void testConstraintTimingMultipleInvocations() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("multi-constraint") + .test(IMetapathExpression.compile("true()")) + .build(); + + INodeItem target = mock(INodeItem.class); + + for (int i = 0; i < 5; i++) { + collector.beforeConstraintEvaluation(constraint, target); + collector.afterConstraintEvaluation(constraint, target); + } + + TimingRecord record = collector.getConstraintTiming("multi-constraint"); + assertNotNull(record); + assertEquals(5, record.getCount()); + assertTrue(record.getMinTimeNs() <= record.getMaxTimeNs()); + } + + @Test + void testLetTimingAccumulation() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + IEnhancedQName name = IEnhancedQName.of("my-var"); + + ILet let = ILet.of( + name, + IMetapathExpression.compile("count(//item)"), + source, + null); + + collector.beforeLetEvaluation(let); + collector.afterLetEvaluation(let); + + TimingRecord record = collector.getLetTiming(let); + assertNotNull(record, "let timing record should exist"); + assertEquals(1, record.getCount()); + } + + @Test + void testOverallValidationTiming() { + TimingCollector collector = new TimingCollector(); + URI document = URI.create("https://example.com/document.xml"); + + collector.beforeValidation(document); + collector.afterValidation(document); + + TimingRecord record = collector.getValidationTiming(); + assertNotNull(record, "validation timing should exist"); + assertEquals(1, record.getCount()); + assertNotNull(record.getStartTimestampUtc()); + assertNotNull(record.getEndTimestampUtc()); + } + + @Test + void testNoTimingWhenNotRecorded() { + TimingCollector collector = new TimingCollector(); + + ILet unrecordedLet = ILet.of( + IEnhancedQName.of("unrecorded"), + IMetapathExpression.compile("1"), + ISource.externalSource("https://example.com/test"), + null); + + assertNull(collector.getPhaseTiming(ValidationPhase.SCHEMA_VALIDATION)); + assertNull(collector.getConstraintTiming("nonexistent")); + assertNull(collector.getLetTiming(unrecordedLet)); + assertNull(collector.getValidationTiming()); + } + + @Test + void testMinMaxTracking() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("minmax-constraint") + .test(IMetapathExpression.compile("true()")) + .build(); + + INodeItem target = mock(INodeItem.class); + + // Run multiple times to get varying durations + for (int i = 0; i < 10; i++) { + collector.beforeConstraintEvaluation(constraint, target); + // No actual delay needed; min/max will reflect real nanoTime deltas + collector.afterConstraintEvaluation(constraint, target); + } + + TimingRecord record = collector.getConstraintTiming("minmax-constraint"); + assertNotNull(record); + assertEquals(10, record.getCount()); + assertTrue(record.getMinTimeNs() >= 0, "minTimeNs should be non-negative"); + assertTrue(record.getMaxTimeNs() >= record.getMinTimeNs(), + "maxTimeNs should be >= minTimeNs"); + assertTrue(record.getTotalTimeNs() >= record.getMinTimeNs(), + "totalTimeNs should be >= minTimeNs"); + } + + @Test + void testThreadSafety() throws Exception { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + + int threadCount = 8; + int iterationsPerThread = 100; + ExecutorService executor = ObjectUtils.notNull(Executors.newFixedThreadPool(threadCount)); + CountDownLatch startLatch = new CountDownLatch(1); + CountDownLatch doneLatch = new CountDownLatch(threadCount); + + try { + for (int t = 0; t < threadCount; t++) { + final int threadId = t; + executor.submit(() -> { + try { + startLatch.await(); + // Each thread uses its own constraint but they share the collector + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("thread-constraint-" + threadId) + .test(IMetapathExpression.compile("true()")) + .build(); + + INodeItem target = mock(INodeItem.class); + + for (int i = 0; i < iterationsPerThread; i++) { + collector.beforeConstraintEvaluation(constraint, target); + collector.afterConstraintEvaluation(constraint, target); + } + } catch (Exception e) { + // fail silently; assertions below will catch issues + } finally { + doneLatch.countDown(); + } + }); + } + + startLatch.countDown(); + assertTrue(doneLatch.await(30, TimeUnit.SECONDS), "threads should complete"); + + // Verify each thread's constraint timing is correct + for (int t = 0; t < threadCount; t++) { + TimingRecord record = collector.getConstraintTiming("thread-constraint-" + t); + assertNotNull(record, "timing for thread " + t + " should exist"); + assertEquals(iterationsPerThread, record.getCount(), + "thread " + t + " should have correct count"); + } + } finally { + executor.shutdown(); + } + } + + @Test + void testNestedConstraintAndLetEvents() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + + IExpectConstraint constraint = IExpectConstraint.builder() + .source(source) + .identifier("outer-constraint") + .test(IMetapathExpression.compile("true()")) + .build(); + + ILet let = ILet.of( + IEnhancedQName.of("nested-var"), + IMetapathExpression.compile("count(//item)"), + source, + null); + + INodeItem target = mock(INodeItem.class); + + // Simulate constraint evaluation that triggers let evaluation + collector.beforeConstraintEvaluation(constraint, target); + collector.beforeLetEvaluation(let); + collector.afterLetEvaluation(let); + collector.afterConstraintEvaluation(constraint, target); + + // Both should be recorded correctly + TimingRecord constraintRecord = collector.getConstraintTiming("outer-constraint"); + assertNotNull(constraintRecord); + assertEquals(1, constraintRecord.getCount()); + + TimingRecord letRecord = collector.getLetTiming(let); + assertNotNull(letRecord); + assertEquals(1, letRecord.getCount()); + + // Constraint time should be >= let time (it contains the let) + assertTrue(constraintRecord.getTotalTimeNs() >= letRecord.getTotalTimeNs(), + "constraint time should include let time"); + } + + @Test + void testGetAllConstraintTimings() { + TimingCollector collector = new TimingCollector(); + ISource source = ISource.externalSource("https://example.com/module"); + INodeItem target = mock(INodeItem.class); + + IExpectConstraint c1 = IExpectConstraint.builder() + .source(source) + .identifier("c1") + .test(IMetapathExpression.compile("true()")) + .build(); + IExpectConstraint c2 = IExpectConstraint.builder() + .source(source) + .identifier("c2") + .test(IMetapathExpression.compile("true()")) + .build(); + + collector.beforeConstraintEvaluation(c1, target); + collector.afterConstraintEvaluation(c1, target); + collector.beforeConstraintEvaluation(c2, target); + collector.afterConstraintEvaluation(c2, target); + + Map all = collector.getConstraintTimings(); + assertEquals(2, all.size()); + assertTrue(all.containsKey("c1")); + assertTrue(all.containsKey("c2")); + } +} diff --git a/core/src/test/java/dev/metaschema/core/model/constraint/ValidationConfigTest.java b/core/src/test/java/dev/metaschema/core/model/constraint/ValidationConfigTest.java new file mode 100644 index 0000000000..f0d0072ba7 --- /dev/null +++ b/core/src/test/java/dev/metaschema/core/model/constraint/ValidationConfigTest.java @@ -0,0 +1,216 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.core.model.constraint; + +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertInstanceOf; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertSame; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import org.junit.jupiter.api.Test; + +import java.net.URI; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; + +import dev.metaschema.core.metapath.item.node.INodeItem; +import dev.metaschema.core.util.ObjectUtils; + +class ValidationConfigTest { + + // === Existing behavior (migrated from ParallelValidationConfigTest) === + + @Test + void testSequentialIsNotParallel() { + ValidationConfig config = ValidationConfig.SEQUENTIAL; + assertFalse(config.isParallel()); + } + + @Test + void testWithThreadsOneIsNotParallel() { + try (ValidationConfig config = ValidationConfig.withThreads(1)) { + assertFalse(config.isParallel()); + } + } + + @Test + void testWithThreadsFourIsParallel() { + try (ValidationConfig config = ValidationConfig.withThreads(4)) { + assertTrue(config.isParallel()); + config.close(); + } + } + + @Test + void testWithThreadsZeroThrows() { + assertThrows(IllegalArgumentException.class, () -> ValidationConfig.withThreads(0)); + } + + @Test + void testWithThreadsNegativeThrows() { + assertThrows(IllegalArgumentException.class, () -> ValidationConfig.withThreads(-1)); + } + + @Test + void testWithExecutorIsParallel() { + ExecutorService executor = ObjectUtils.notNull(Executors.newFixedThreadPool(2)); + try (ValidationConfig config = ValidationConfig.withExecutor(executor)) { + assertTrue(config.isParallel()); + } finally { + executor.shutdown(); + } + } + + @SuppressWarnings("null") + @Test + void testWithExecutorNullThrows() { + assertThrows(NullPointerException.class, () -> ValidationConfig.withExecutor(null)); + } + + @Test + void testCloseShutdownsInternalExecutor() { + try (ValidationConfig config = ValidationConfig.withThreads(2)) { + ExecutorService executor = config.getExecutor(); + assertFalse(executor.isShutdown()); + config.close(); + assertTrue(executor.isShutdown()); + } + } + + @Test + void testCloseDoesNotShutdownExternalExecutor() { + ExecutorService executor = ObjectUtils.notNull(Executors.newFixedThreadPool(2)); + try (ValidationConfig config = ValidationConfig.withExecutor(executor)) { + config.close(); + assertFalse(executor.isShutdown()); + } finally { + executor.shutdown(); + } + } + + // === New ValidationEventListener tests === + + @Test + void testDefaultListenerIsNoOp() { + ValidationConfig config = ValidationConfig.SEQUENTIAL; + ValidationEventListener listener = config.getListener(); + assertNotNull(listener); + assertInstanceOf(NoOpValidationEventListener.class, listener); + } + + @Test + void testWithListenerReturnsConfigWithListener() { + TestListener listener = new TestListener(); + try (ValidationConfig config = ValidationConfig.withThreads(2).withListener(listener)) { + assertSame(listener, config.getListener()); + } + } + + @Test + void testSequentialWithListenerReturnsNewConfig() { + TestListener listener = new TestListener(); + try (ValidationConfig config = ValidationConfig.SEQUENTIAL.withListener(listener)) { + assertSame(listener, config.getListener()); + assertFalse(config.isParallel()); + } + } + + @SuppressWarnings("null") + @Test + void testWithListenerNullThrows() { + assertThrows(NullPointerException.class, + () -> ValidationConfig.SEQUENTIAL.withListener(null)); + } + + @Test + void testWithListenerPreservesParallelConfig() { + TestListener listener = new TestListener(); + try (ValidationConfig config = ValidationConfig.withThreads(4).withListener(listener)) { + assertTrue(config.isParallel()); + assertSame(listener, config.getListener()); + } + } + + // === addListener tests === + + @Test + void testAddListenerCreatesComposite() { + TestListener listener1 = new TestListener(); + TestListener listener2 = new TestListener(); + try (ValidationConfig config = ValidationConfig.SEQUENTIAL + .withListener(listener1) + .addListener(listener2)) { + assertInstanceOf(CompositeValidationEventListener.class, config.getListener()); + } + } + + @Test + void testAddListenerToNoOpReplacesDirectly() { + TestListener listener = new TestListener(); + try (ValidationConfig config = ValidationConfig.SEQUENTIAL.addListener(listener)) { + assertSame(listener, config.getListener()); + } + } + + @Test + void testAddListenerPreservesParallelConfig() { + TestListener listener1 = new TestListener(); + TestListener listener2 = new TestListener(); + try (ValidationConfig config = ValidationConfig.withThreads(4) + .withListener(listener1) + .addListener(listener2)) { + assertTrue(config.isParallel()); + assertInstanceOf(CompositeValidationEventListener.class, config.getListener()); + } + } + + /** + * A simple test listener that tracks whether events were called. + */ + private static class TestListener implements ValidationEventListener { + @Override + public void beforeValidation(URI document) { + // test stub + } + + @Override + public void afterValidation(URI document) { + // test stub + } + + @Override + public void beforePhase(ValidationPhase phase) { + // test stub + } + + @Override + public void afterPhase(ValidationPhase phase) { + // test stub + } + + @Override + public void beforeConstraintEvaluation(IConstraint constraint, INodeItem target) { + // test stub + } + + @Override + public void afterConstraintEvaluation(IConstraint constraint, INodeItem target) { + // test stub + } + + @Override + public void beforeLetEvaluation(ILet let) { + // test stub + } + + @Override + public void afterLetEvaluation(ILet let) { + // test stub + } + } +} diff --git a/databind-modules/modules b/databind-modules/modules index fc794cc7d0..44c78494c1 160000 --- a/databind-modules/modules +++ b/databind-modules/modules @@ -1 +1 @@ -Subproject commit fc794cc7d0ef92c66658978654e88b752cc496ae +Subproject commit 44c78494c1c8b487b8a6e30e631fb7d3fdd05f13 diff --git a/databind-modules/pom.xml b/databind-modules/pom.xml index 1adf5e5d60..265426c450 100644 --- a/databind-modules/pom.xml +++ b/databind-modules/pom.xml @@ -49,7 +49,6 @@ dev.harrel json-schema - 1.9.0 diff --git a/databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java b/databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java index 26ac997b16..77eacf2528 100644 --- a/databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java +++ b/databind-modules/src/main/java/dev/metaschema/modules/sarif/SarifValidationHandler.java @@ -7,27 +7,38 @@ import org.schemastore.json.sarif.x210.Artifact; import org.schemastore.json.sarif.x210.ArtifactLocation; +import org.schemastore.json.sarif.x210.Invocation; +import org.schemastore.json.sarif.x210.LetTimingEntry; import org.schemastore.json.sarif.x210.Location; import org.schemastore.json.sarif.x210.LogicalLocation; import org.schemastore.json.sarif.x210.Message; import org.schemastore.json.sarif.x210.MultiformatMessageString; +import org.schemastore.json.sarif.x210.Notification; import org.schemastore.json.sarif.x210.PhysicalLocation; +import org.schemastore.json.sarif.x210.PropertyBag; import org.schemastore.json.sarif.x210.Region; import org.schemastore.json.sarif.x210.ReportingDescriptor; import org.schemastore.json.sarif.x210.Result; import org.schemastore.json.sarif.x210.Run; import org.schemastore.json.sarif.x210.Sarif; import org.schemastore.json.sarif.x210.SarifModule; +import org.schemastore.json.sarif.x210.TimingData; import org.schemastore.json.sarif.x210.Tool; import org.schemastore.json.sarif.x210.ToolComponent; import java.io.IOException; import java.io.StringWriter; +import java.math.BigDecimal; import java.math.BigInteger; +import java.math.RoundingMode; import java.net.URI; import java.net.URISyntaxException; import java.nio.file.Path; import java.nio.file.StandardOpenOption; +import java.time.Instant; +import java.time.ZoneOffset; +import java.time.ZonedDateTime; +import java.util.ArrayList; import java.util.Collection; import java.util.LinkedHashMap; import java.util.LinkedList; @@ -35,16 +46,23 @@ import java.util.Map; import java.util.Set; import java.util.UUID; +import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.atomic.AtomicInteger; import dev.metaschema.core.datatype.markup.MarkupLine; import dev.metaschema.core.datatype.markup.MarkupMultiline; +import dev.metaschema.core.metapath.item.node.INodeItem; import dev.metaschema.core.model.IAttributable; import dev.metaschema.core.model.IResourceLocation; import dev.metaschema.core.model.MetaschemaException; import dev.metaschema.core.model.constraint.ConstraintValidationFinding; import dev.metaschema.core.model.constraint.IConstraint; import dev.metaschema.core.model.constraint.IConstraint.Level; +import dev.metaschema.core.model.constraint.ILet; +import dev.metaschema.core.model.constraint.TimingCollector; +import dev.metaschema.core.model.constraint.TimingRecord; +import dev.metaschema.core.model.constraint.ValidationEventListener; +import dev.metaschema.core.model.constraint.ValidationPhase; import dev.metaschema.core.model.validation.IValidationFinding; import dev.metaschema.core.model.validation.JsonSchemaContentValidator.JsonValidationFinding; import dev.metaschema.core.model.validation.XmlSchemaContentValidator.XmlValidationFinding; @@ -63,7 +81,7 @@ * document based on a set of validation findings. */ @SuppressWarnings("PMD.CouplingBetweenObjects") -public final class SarifValidationHandler { +public final class SarifValidationHandler implements ValidationEventListener { private enum Kind { NOT_APPLICABLE("notApplicable"), PASS("pass"), @@ -147,6 +165,18 @@ public String getLabel() { @NonNull private final SchemaRuleRecord schemaRule = new SchemaRuleRecord(); private boolean schemaValid = true; + @Nullable + private TimingCollector timingCollector; + @NonNull + private final Instant constructionTimestamp = Instant.now(); + private final ThreadLocal currentEvaluationStartNanos = new ThreadLocal<>(); + private final ThreadLocal> currentEvaluationResults = new ThreadLocal<>(); + private final ThreadLocal currentLetStartNanos = new ThreadLocal<>(); + @SuppressWarnings("PMD.UseConcurrentHashMap") + private final ThreadLocal> currentLetDurations = new ThreadLocal<>(); + @NonNull + private final ConcurrentHashMap evaluationTimings + = new ConcurrentHashMap<>(); /** * Construct a new validation handler. @@ -177,6 +207,136 @@ private IVersionInfo getToolVersion() { return toolVersion; } + /** + * Set the timing collector to enrich SARIF output with performance data. + *

+ * When set, the generated SARIF document will include: + *

    + *
  • An invocation element with start/end timestamps
    • + *
  • Phase timing as tool execution notifications
    • + *
  • Per-constraint timing in rule properties
    • + *
+ * + * @param collector + * the timing collector containing measurement data, or {@code null} to + * disable timing output + */ + public void setTimingCollector(@Nullable TimingCollector collector) { + this.timingCollector = collector; + } + + @Override + public void beforeValidation(@NonNull URI document) { + // No-op: always-on timing uses construction timestamp + } + + @Override + public void afterValidation(@NonNull URI document) { + // No-op: always-on timing captures end time at SARIF generation + } + + @Override + public void beforePhase(@NonNull ValidationPhase phase) { + // No-op: phase timing is handled by TimingCollector + } + + @Override + public void afterPhase(@NonNull ValidationPhase phase) { + // No-op: phase timing is handled by TimingCollector + } + + @Override + public void beforeConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + currentEvaluationStartNanos.set(System.nanoTime()); + currentEvaluationResults.set(new ArrayList<>()); + currentLetDurations.set(new LinkedHashMap<>()); + } + + @SuppressWarnings("PMD.NullAssignment") // ThreadLocal cleanup + @Override + public void afterConstraintEvaluation(@NonNull IConstraint constraint, @NonNull INodeItem target) { + Long startNanos = currentEvaluationStartNanos.get(); + List evaluationResults = currentEvaluationResults.get(); + Map letDurations = currentLetDurations.get(); + + if (startNanos != null) { + long durationNs = System.nanoTime() - startNanos; + Map snapshotLetDurations = letDurations != null && !letDurations.isEmpty() + ? new LinkedHashMap<>(letDurations) + : null; + + // Set timing on inline results (added during this evaluation) + if (evaluationResults != null) { + for (ConstraintResult result : evaluationResults) { + result.setEvaluationDurationNs(durationNs); + if (snapshotLetDurations != null) { + result.setLetDurations(snapshotLetDurations); + } + } + } + + // Store for deferred lookup (when findings are added after validation) + evaluationTimings.put(constraint, + new EvaluationTimingSnapshot(durationNs, snapshotLetDurations)); + } + + currentEvaluationStartNanos.remove(); + currentEvaluationResults.remove(); + currentLetStartNanos.remove(); + currentLetDurations.remove(); + } + + @Override + public void beforeLetEvaluation(@NonNull ILet let) { + currentLetStartNanos.set(System.nanoTime()); + } + + @Override + public void afterLetEvaluation(@NonNull ILet let) { + Long startNanos = currentLetStartNanos.get(); + Map letDurations = currentLetDurations.get(); + if (startNanos != null && letDurations != null) { + long durationNs = System.nanoTime() - startNanos; + letDurations.merge(let, durationNs, Long::sum); + } + currentLetStartNanos.remove(); + } + + @NonNull + private static final BigDecimal NS_PER_MS = BigDecimal.valueOf(1_000_000L); + + /** + * Convert nanoseconds to milliseconds as a BigDecimal with 3 decimal places. + * + * @param nanoseconds + * the duration in nanoseconds + * @return the duration in milliseconds + */ + @NonNull + private static BigDecimal nsToMs(long nanoseconds) { + return ObjectUtils.notNull( + BigDecimal.valueOf(nanoseconds).divide(NS_PER_MS, 3, RoundingMode.HALF_UP)); + } + + /** + * Convert a {@link TimingRecord} to a SARIF {@link TimingData} object. + * + * @param record + * the timing record to convert + * @return the SARIF timing data + */ + @NonNull + private static TimingData toTimingData(@NonNull TimingRecord record) { + TimingData data = new TimingData(); + data.setTotalMs(nsToMs(record.getTotalTimeNs())); + data.setCount(BigInteger.valueOf(record.getCount())); + if (record.getCount() > 0) { + data.setMinMs(nsToMs(record.getMinTimeNs())); + data.setMaxMs(nsToMs(record.getMaxTimeNs())); + } + return data; + } + /** * Register a collection of validation finding. * @@ -242,7 +402,26 @@ private void addXmlValidationFinding(@NonNull XmlValidationFinding finding) { } private void addConstraintValidationFinding(@NonNull ConstraintValidationFinding finding) { - results.add(new ConstraintResult(finding)); + ConstraintResult constraintResult = new ConstraintResult(finding); + results.add(constraintResult); + + // Track for per-evaluation timing if within a constraint evaluation (inline) + List evaluationResults = currentEvaluationResults.get(); + if (evaluationResults != null) { + evaluationResults.add(constraintResult); + } else { + // Deferred pattern: look up timing from the most recent evaluation + for (IConstraint constraint : finding.getConstraints()) { + EvaluationTimingSnapshot snapshot = evaluationTimings.get(constraint); + if (snapshot != null) { + constraintResult.setEvaluationDurationNs(snapshot.durationNs); + if (snapshot.letDurations != null) { + constraintResult.setLetDurations(snapshot.letDurations); + } + break; + } + } + } } /** @@ -288,9 +467,96 @@ private Sarif generateSarif(@NonNull URI outputUri) throws IOException { run.setTool(tool); } + enrichWithTiming(run); + return sarif; } + /** + * Enrich the SARIF run with timing data. + *

+ * Always creates an invocation with start/end timestamps (always-on timing). If + * a timing collector is set, overrides timestamps from the collector and adds + * phase/let-statement timing as tool execution notifications. + * + * @param run + * the SARIF run to enrich + */ + @SuppressWarnings("PMD.CognitiveComplexity") + private void enrichWithTiming(@NonNull Run run) { + // Always create invocation with timestamps (always-on timing) + Invocation invocation = new Invocation(); + invocation.setExecutionSuccessful(Boolean.TRUE); + invocation.setStartTimeUtc(ZonedDateTime.ofInstant(constructionTimestamp, ZoneOffset.UTC)); + invocation.setEndTimeUtc(ZonedDateTime.ofInstant(Instant.now(), ZoneOffset.UTC)); + + TimingCollector collector = this.timingCollector; + if (collector != null) { + // Override with collector timestamps if available + TimingRecord validationTiming = collector.getValidationTiming(); + if (validationTiming != null) { + Instant start = validationTiming.getStartTimestampUtc(); + if (start != null) { + invocation.setStartTimeUtc(ZonedDateTime.ofInstant(start, ZoneOffset.UTC)); + } + Instant end = validationTiming.getEndTimestampUtc(); + if (end != null) { + invocation.setEndTimeUtc(ZonedDateTime.ofInstant(end, ZoneOffset.UTC)); + } + } + + // Add phase timing as notifications + for (Map.Entry entry : collector.getPhaseTimings().entrySet()) { + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + Notification notification = new Notification(); + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + Message msg = new Message(); + msg.setText("Phase: " + entry.getKey().name()); + notification.setMessage(msg); + + TimingRecord phaseRecord = entry.getValue(); + Instant phaseEnd = phaseRecord.getEndTimestampUtc(); + if (phaseEnd != null) { + notification.setTimeUtc(ZonedDateTime.ofInstant(phaseEnd, ZoneOffset.UTC)); + } + + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + PropertyBag phaseProps = new PropertyBag(); + phaseProps.setTiming(toTimingData(phaseRecord)); + notification.setProperties(phaseProps); + + invocation.addToolExecutionNotification(notification); + } + + // Add let-statement timing as notifications + for (Map.Entry entry : collector.getLetTimings().entrySet()) { + ILet let = entry.getKey(); + + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + Notification notification = new Notification(); + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + Message msg = new Message(); + msg.setText("$" + let.getName().getLocalName() + " := " + let.getValueExpression().getPath()); + notification.setMessage(msg); + + TimingRecord letRecord = entry.getValue(); + Instant letEnd = letRecord.getEndTimestampUtc(); + if (letEnd != null) { + notification.setTimeUtc(ZonedDateTime.ofInstant(letEnd, ZoneOffset.UTC)); + } + + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + PropertyBag letProps = new PropertyBag(); + letProps.setTiming(toTimingData(letRecord)); + notification.setProperties(letProps); + + invocation.addToolExecutionNotification(notification); + } + } + + run.addInvocation(invocation); + } + /** * Write the collection of findings to a string in SARIF format. * @@ -501,11 +767,23 @@ public List generateResults(@NonNull URI output) throws IOException { private final class ConstraintResult extends AbstractResult { + @Nullable + private Long evaluationDurationNs; + @Nullable + private Map letDurations; protected ConstraintResult(@NonNull ConstraintValidationFinding finding) { super(finding); } + void setEvaluationDurationNs(long durationNs) { + this.evaluationDurationNs = durationNs; + } + + void setLetDurations(@NonNull Map durations) { + this.letDurations = durations; + } + @Override public List generateResults(@NonNull URI output) throws IOException { ConstraintValidationFinding finding = getFinding(); @@ -532,11 +810,48 @@ public List generateResults(@NonNull URI output) throws IOException { result.setLevel(level.getLabel()); message(finding, result); location(finding, result, output); + addPerResultTiming(result); retval.add(result); } return retval; } + + @SuppressWarnings("PMD.CognitiveComplexity") + private void addPerResultTiming(@NonNull Result result) { + Long durationNs = this.evaluationDurationNs; + if (durationNs == null) { + return; + } + + PropertyBag props = result.getProperties(); + if (props == null) { + props = new PropertyBag(); + result.setProperties(props); + } + + TimingData timing = new TimingData(); + timing.setTotalMs(nsToMs(durationNs)); + timing.setCount(BigInteger.ONE); + props.setTiming(timing); + + Map letDurs = this.letDurations; + if (letDurs != null) { + for (Map.Entry entry : letDurs.entrySet()) { + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + LetTimingEntry letEntry = new LetTimingEntry(); + letEntry.setName(entry.getKey().getName().getLocalName()); + + @SuppressWarnings("PMD.AvoidInstantiatingObjectsInLoops") + TimingData letTiming = new TimingData(); + letTiming.setTotalMs(nsToMs(entry.getValue())); + letTiming.setCount(BigInteger.ONE); + letEntry.setTiming(letTiming); + + props.addLetTimingEntry(letEntry); + } + } + } } private abstract class AbstractRuleRecord { @@ -645,6 +960,20 @@ protected ReportingDescriptor generate() { retval.setHelp(help); } + // Add timing data if available + TimingCollector collector = timingCollector; + if (collector != null) { + TimingRecord record = collector.getConstraintTiming(constraint.getInternalIdentifier()); + if (record != null) { + PropertyBag props = retval.getProperties(); + if (props == null) { + props = new PropertyBag(); + retval.setProperties(props); + } + props.setTiming(toTimingData(record)); + } + } + return retval; } @@ -682,4 +1011,19 @@ public ArtifactLocation generateArtifactLocation(@NonNull URI baseUri) throws IO return location; } } + + /** + * Snapshot of per-evaluation timing data, stored for deferred lookup when + * findings are added after validation completes. + */ + private static final class EvaluationTimingSnapshot { + final long durationNs; + @Nullable + final Map letDurations; + + EvaluationTimingSnapshot(long durationNs, @Nullable Map letDurations) { + this.durationNs = durationNs; + this.letDurations = letDurations; + } + } } diff --git a/databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java b/databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java new file mode 100644 index 0000000000..a01e9847c9 --- /dev/null +++ b/databind-modules/src/test/java/dev/metaschema/modules/sarif/SarifValidationHandlerTimingTest.java @@ -0,0 +1,573 @@ +/* + * SPDX-FileCopyrightText: none + * SPDX-License-Identifier: CC0-1.0 + */ + +package dev.metaschema.modules.sarif; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +import org.jmock.Expectations; +import org.jmock.junit5.JUnit5Mockery; +import org.jmock.lib.concurrent.Synchroniser; +import org.json.JSONArray; +import org.json.JSONObject; +import org.json.JSONTokener; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import java.io.IOException; +import java.io.Reader; +import java.net.URI; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.util.Map; +import java.util.Set; +import java.util.StringJoiner; + +import dev.harrel.jsonschema.Dialects; +import dev.harrel.jsonschema.JsonNode; +import dev.harrel.jsonschema.Validator; +import dev.harrel.jsonschema.ValidatorFactory; +import dev.harrel.jsonschema.providers.OrgJsonNode; +import dev.metaschema.core.datatype.markup.MarkupLine; +import dev.metaschema.core.metapath.IMetapathExpression; +import dev.metaschema.core.metapath.item.node.INodeItem; +import dev.metaschema.core.model.IResourceLocation; +import dev.metaschema.core.model.ISource; +import dev.metaschema.core.model.constraint.ConstraintValidationFinding; +import dev.metaschema.core.model.constraint.IConstraint; +import dev.metaschema.core.model.constraint.ILet; +import dev.metaschema.core.model.constraint.TimingCollector; +import dev.metaschema.core.model.constraint.ValidationPhase; +import dev.metaschema.core.model.validation.IValidationFinding; +import dev.metaschema.core.qname.IEnhancedQName; +import dev.metaschema.core.util.IVersionInfo; +import dev.metaschema.core.util.ObjectUtils; +import dev.metaschema.databind.IBindingContext; + +class SarifValidationHandlerTimingTest { + @RegisterExtension + public final JUnit5Mockery mockery = new JUnit5Mockery() { + { + setThreadingPolicy(new Synchroniser()); + } + }; + + @Test + void testTimingEnrichmentInSarifOutput() throws IOException { + IVersionInfo versionInfo = mockery.mock(IVersionInfo.class); + IConstraint constraintA = ObjectUtils.notNull(mockery.mock(IConstraint.class, "constraintA")); + INodeItem node = ObjectUtils.notNull(mockery.mock(INodeItem.class)); + IResourceLocation location = mockery.mock(IResourceLocation.class); + + Path sourceFile = ObjectUtils.requireNonNull(Paths.get(".", "source.json").toAbsolutePath()); + + mockery.checking(new Expectations() { + { // NOPMD - intentional + allowing(versionInfo).getName(); + will(returnValue("test")); + allowing(versionInfo).getVersion(); + will(returnValue("0.0.0")); + + allowing(constraintA).getLevel(); + will(returnValue(IConstraint.Level.ERROR)); + allowing(constraintA).getId(); + will(returnValue(null)); + allowing(constraintA).getFormalName(); + will(returnValue("a formal name")); + allowing(constraintA).getDescription(); + will(returnValue(MarkupLine.fromMarkdown("a description"))); + allowing(constraintA).getProperties(); + will(returnValue(Map.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_URL_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_TEXT_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_MARKDOWN_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getInternalIdentifier(); + will(returnValue("test-constraint-id")); + + allowing(node).getLocation(); + will(returnValue(location)); + allowing(node).getBaseUri(); + will(returnValue(sourceFile.toUri())); + allowing(node).getMetapath(); + will(returnValue("/node/child")); + + allowing(location).getLine(); + will(returnValue(10)); + allowing(location).getColumn(); + will(returnValue(0)); + allowing(location).getByteOffset(); + will(returnValue(-1L)); + allowing(location).getCharOffset(); + will(returnValue(-1L)); + } + }); + + // Create and populate TimingCollector with realistic events + TimingCollector collector = new TimingCollector(); + URI docUri = ObjectUtils.notNull(sourceFile.toUri()); + + collector.beforeValidation(docUri); + collector.beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + collector.beforeConstraintEvaluation(constraintA, node); + busyWait(); + collector.afterConstraintEvaluation(constraintA, node); + collector.afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + collector.afterValidation(docUri); + + // Create handler with timing collector + SarifValidationHandler handler + = new SarifValidationHandler(ObjectUtils.notNull(sourceFile.toUri()), versionInfo); + handler.setTimingCollector(collector); + + handler.addFinding(ConstraintValidationFinding.builder(constraintA, node) + .kind(IValidationFinding.Kind.FAIL) + .build()); + + String sarifOutput = handler.writeToString(IBindingContext.newInstance()); + JSONObject sarif = new JSONObject(sarifOutput); + + // Verify invocations exist in the run + JSONArray runs = sarif.getJSONArray("runs"); + JSONObject run = runs.getJSONObject(0); + assertTrue(run.has("invocations"), "Run should have invocations when timing is enabled"); + + JSONArray invocations = run.getJSONArray("invocations"); + assertEquals(1, invocations.length(), "Should have exactly one invocation"); + + JSONObject invocation = invocations.getJSONObject(0); + assertTrue(invocation.has("startTimeUtc"), "Invocation should have startTimeUtc"); + assertTrue(invocation.has("endTimeUtc"), "Invocation should have endTimeUtc"); + assertTrue(invocation.getBoolean("executionSuccessful"), "executionSuccessful should be true"); + + // Verify phase timing as notifications + assertTrue(invocation.has("toolExecutionNotifications"), + "Invocation should have toolExecutionNotifications for phase timing"); + JSONArray notifications = invocation.getJSONArray("toolExecutionNotifications"); + assertTrue(notifications.length() > 0, "Should have at least one phase timing notification"); + + boolean foundConstraintPhase = false; + for (int i = 0; i < notifications.length(); i++) { + JSONObject notification = notifications.getJSONObject(i); + JSONObject message = notification.getJSONObject("message"); + if (message.getString("text").contains("CONSTRAINT_VALIDATION")) { + foundConstraintPhase = true; + assertTrue(notification.has("properties"), "Phase notification should have properties"); + JSONObject phaseProps = notification.getJSONObject("properties"); + assertTrue(phaseProps.has("timing"), "Phase properties should have timing"); + JSONObject phaseTiming = phaseProps.getJSONObject("timing"); + assertTrue(phaseTiming.has("totalMs"), "Phase timing should have totalMs"); + assertTrue(phaseTiming.has("count"), "Phase timing should have count"); + break; + } + } + assertTrue(foundConstraintPhase, "Should have a notification for CONSTRAINT_VALIDATION phase"); + + // Verify constraint timing in rule properties + JSONObject tool = run.getJSONObject("tool"); + JSONObject driver = tool.getJSONObject("driver"); + JSONArray rules = driver.getJSONArray("rules"); + assertTrue(rules.length() > 0, "Should have at least one rule"); + + boolean foundTimingOnRule = false; + for (int i = 0; i < rules.length(); i++) { + JSONObject rule = rules.getJSONObject(i); + if (rule.has("properties")) { + JSONObject props = rule.getJSONObject("properties"); + if (props.has("timing")) { + foundTimingOnRule = true; + JSONObject timing = props.getJSONObject("timing"); + assertTrue(timing.has("totalMs"), "Rule timing should have totalMs"); + assertTrue(timing.has("count"), "Rule timing should have count"); + assertEquals(1, timing.getInt("count"), "Constraint was evaluated once"); + break; + } + } + } + assertTrue(foundTimingOnRule, "Should have timing data on constraint rule properties"); + } + + @Test + void testNoTimingWhenCollectorNotSet() throws IOException { + IVersionInfo versionInfo = mockery.mock(IVersionInfo.class); + IConstraint constraintA = ObjectUtils.notNull(mockery.mock(IConstraint.class, "constraintA")); + INodeItem node = ObjectUtils.notNull(mockery.mock(INodeItem.class)); + IResourceLocation location = mockery.mock(IResourceLocation.class); + + Path sourceFile = ObjectUtils.requireNonNull(Paths.get(".", "source.json").toAbsolutePath()); + + mockery.checking(new Expectations() { + { // NOPMD - intentional + allowing(versionInfo).getName(); + will(returnValue("test")); + allowing(versionInfo).getVersion(); + will(returnValue("0.0.0")); + + allowing(constraintA).getLevel(); + will(returnValue(IConstraint.Level.ERROR)); + allowing(constraintA).getId(); + will(returnValue(null)); + allowing(constraintA).getFormalName(); + will(returnValue("a formal name")); + allowing(constraintA).getDescription(); + will(returnValue(MarkupLine.fromMarkdown("a description"))); + allowing(constraintA).getProperties(); + will(returnValue(Map.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_URL_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_TEXT_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_MARKDOWN_KEY); + will(returnValue(Set.of())); + + allowing(node).getLocation(); + will(returnValue(location)); + allowing(node).getBaseUri(); + will(returnValue(sourceFile.toUri())); + allowing(node).getMetapath(); + will(returnValue("/node/child")); + + allowing(location).getLine(); + will(returnValue(10)); + allowing(location).getColumn(); + will(returnValue(0)); + allowing(location).getByteOffset(); + will(returnValue(-1L)); + allowing(location).getCharOffset(); + will(returnValue(-1L)); + } + }); + + SarifValidationHandler handler + = new SarifValidationHandler(ObjectUtils.notNull(sourceFile.toUri()), versionInfo); + // No timing collector set + + handler.addFinding(ConstraintValidationFinding.builder(constraintA, node) + .kind(IValidationFinding.Kind.FAIL) + .build()); + + String sarifOutput = handler.writeToString(IBindingContext.newInstance()); + JSONObject sarif = new JSONObject(sarifOutput); + + JSONArray runs = sarif.getJSONArray("runs"); + JSONObject run = runs.getJSONObject(0); + + // Always-on: invocations should always be present with timestamps + assertTrue(run.has("invocations"), "Run should always have invocations (always-on timing)"); + JSONArray invocations = run.getJSONArray("invocations"); + assertEquals(1, invocations.length()); + JSONObject invocation = invocations.getJSONObject(0); + assertTrue(invocation.has("startTimeUtc"), "Invocation should always have startTimeUtc"); + assertTrue(invocation.has("endTimeUtc"), "Invocation should always have endTimeUtc"); + + // Without timing collector, should NOT have phase/let timing notifications + assertFalse(invocation.has("toolExecutionNotifications"), + "Invocation should not have timing notifications when collector is not set"); + + // Rules should not have timing properties + JSONObject tool = run.getJSONObject("tool"); + JSONObject driver = tool.getJSONObject("driver"); + JSONArray rules = driver.getJSONArray("rules"); + for (int i = 0; i < rules.length(); i++) { + JSONObject rule = rules.getJSONObject(i); + if (rule.has("properties")) { + JSONObject props = rule.getJSONObject("properties"); + assertFalse(props.has("timing"), "Rule should not have timing when collector is not set"); + } + } + } + + @Test + void testPerResultEvaluationTiming() throws IOException { + IVersionInfo versionInfo = mockery.mock(IVersionInfo.class); + IConstraint constraintA = ObjectUtils.notNull(mockery.mock(IConstraint.class, "constraintA")); + INodeItem node = ObjectUtils.notNull(mockery.mock(INodeItem.class)); + IResourceLocation location = mockery.mock(IResourceLocation.class); + + Path sourceFile = ObjectUtils.requireNonNull(Paths.get(".", "source.json").toAbsolutePath()); + + mockery.checking(new Expectations() { + { // NOPMD - intentional + allowing(versionInfo).getName(); + will(returnValue("test")); + allowing(versionInfo).getVersion(); + will(returnValue("0.0.0")); + + allowing(constraintA).getLevel(); + will(returnValue(IConstraint.Level.ERROR)); + allowing(constraintA).getId(); + will(returnValue("per-result-constraint")); + allowing(constraintA).getFormalName(); + will(returnValue("per-result test")); + allowing(constraintA).getDescription(); + will(returnValue(MarkupLine.fromMarkdown("a description"))); + allowing(constraintA).getProperties(); + will(returnValue(Map.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_URL_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_TEXT_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_MARKDOWN_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getInternalIdentifier(); + will(returnValue("per-result-id")); + + allowing(node).getLocation(); + will(returnValue(location)); + allowing(node).getBaseUri(); + will(returnValue(sourceFile.toUri())); + allowing(node).getMetapath(); + will(returnValue("/node/child")); + + allowing(location).getLine(); + will(returnValue(10)); + allowing(location).getColumn(); + will(returnValue(0)); + allowing(location).getByteOffset(); + will(returnValue(-1L)); + allowing(location).getCharOffset(); + will(returnValue(-1L)); + } + }); + + SarifValidationHandler handler + = new SarifValidationHandler(ObjectUtils.notNull(sourceFile.toUri()), versionInfo); + + // Fire constraint evaluation events on the handler - finding added during + // evaluation + handler.beforeConstraintEvaluation(constraintA, node); + busyWait(); + handler.addFinding(ConstraintValidationFinding.builder(constraintA, node) + .kind(IValidationFinding.Kind.FAIL) + .build()); + handler.afterConstraintEvaluation(constraintA, node); + + String sarifOutput = handler.writeToString(IBindingContext.newInstance()); + JSONObject sarif = new JSONObject(sarifOutput); + + JSONArray results = sarif.getJSONArray("runs").getJSONObject(0).getJSONArray("results"); + assertTrue(results.length() > 0, "Should have at least one result"); + + JSONObject result = results.getJSONObject(0); + assertTrue(result.has("properties"), "Result should have properties with per-evaluation timing"); + + JSONObject props = result.getJSONObject("properties"); + assertTrue(props.has("timing"), "Result properties should have timing data"); + + JSONObject timing = props.getJSONObject("timing"); + assertTrue(timing.has("totalMs"), "Per-result timing should have totalMs"); + } + + @Test + void testPerResultLetTiming() throws IOException { + IVersionInfo versionInfo = mockery.mock(IVersionInfo.class); + IConstraint constraintA = ObjectUtils.notNull(mockery.mock(IConstraint.class, "constraintA")); + INodeItem node = ObjectUtils.notNull(mockery.mock(INodeItem.class)); + IResourceLocation location = mockery.mock(IResourceLocation.class); + + Path sourceFile = ObjectUtils.requireNonNull(Paths.get(".", "source.json").toAbsolutePath()); + + ILet let = ILet.of( + IEnhancedQName.of("test-var"), + IMetapathExpression.compile("count(//item)"), + ISource.externalSource("https://example.com/module"), + null); + + mockery.checking(new Expectations() { + { // NOPMD - intentional + allowing(versionInfo).getName(); + will(returnValue("test")); + allowing(versionInfo).getVersion(); + will(returnValue("0.0.0")); + + allowing(constraintA).getLevel(); + will(returnValue(IConstraint.Level.ERROR)); + allowing(constraintA).getId(); + will(returnValue("let-timing-constraint")); + allowing(constraintA).getFormalName(); + will(returnValue("let timing test")); + allowing(constraintA).getDescription(); + will(returnValue(MarkupLine.fromMarkdown("a description"))); + allowing(constraintA).getProperties(); + will(returnValue(Map.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_URL_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_TEXT_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_MARKDOWN_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getInternalIdentifier(); + will(returnValue("let-timing-id")); + + allowing(node).getLocation(); + will(returnValue(location)); + allowing(node).getBaseUri(); + will(returnValue(sourceFile.toUri())); + allowing(node).getMetapath(); + will(returnValue("/node/child")); + + allowing(location).getLine(); + will(returnValue(10)); + allowing(location).getColumn(); + will(returnValue(0)); + allowing(location).getByteOffset(); + will(returnValue(-1L)); + allowing(location).getCharOffset(); + will(returnValue(-1L)); + } + }); + + SarifValidationHandler handler + = new SarifValidationHandler(ObjectUtils.notNull(sourceFile.toUri()), versionInfo); + + // Simulate constraint evaluation with let evaluation inside + handler.beforeConstraintEvaluation(constraintA, node); + handler.beforeLetEvaluation(let); + busyWait(); + handler.afterLetEvaluation(let); + handler.addFinding(ConstraintValidationFinding.builder(constraintA, node) + .kind(IValidationFinding.Kind.FAIL) + .build()); + handler.afterConstraintEvaluation(constraintA, node); + + String sarifOutput = handler.writeToString(IBindingContext.newInstance()); + JSONObject sarif = new JSONObject(sarifOutput); + + JSONArray results = sarif.getJSONArray("runs").getJSONObject(0).getJSONArray("results"); + assertTrue(results.length() > 0, "Should have at least one result"); + + JSONObject result = results.getJSONObject(0); + assertTrue(result.has("properties"), "Result should have properties"); + + JSONObject props = result.getJSONObject("properties"); + assertTrue(props.has("letTimings"), "Result properties should have letTimings"); + + JSONArray letTimings = props.getJSONArray("letTimings"); + assertTrue(letTimings.length() > 0, "Should have at least one let timing entry"); + + JSONObject letEntry = letTimings.getJSONObject(0); + assertEquals("test-var", letEntry.getString("name"), "Let timing entry should have correct name"); + assertTrue(letEntry.has("timing"), "Let timing entry should have timing data"); + } + + @Test + void testTimingOutputPassesSarifSchemaValidation() throws IOException { + IVersionInfo versionInfo = mockery.mock(IVersionInfo.class); + IConstraint constraintA = ObjectUtils.notNull(mockery.mock(IConstraint.class, "constraintA")); + INodeItem node = ObjectUtils.notNull(mockery.mock(INodeItem.class)); + IResourceLocation location = mockery.mock(IResourceLocation.class); + + Path sourceFile = ObjectUtils.requireNonNull(Paths.get(".", "source.json").toAbsolutePath()); + + mockery.checking(new Expectations() { + { // NOPMD - intentional + allowing(versionInfo).getName(); + will(returnValue("test")); + allowing(versionInfo).getVersion(); + will(returnValue("0.0.0")); + + allowing(constraintA).getLevel(); + will(returnValue(IConstraint.Level.ERROR)); + allowing(constraintA).getId(); + will(returnValue("test-rule-1")); + allowing(constraintA).getFormalName(); + will(returnValue("a formal name")); + allowing(constraintA).getDescription(); + will(returnValue(MarkupLine.fromMarkdown("a description"))); + allowing(constraintA).getProperties(); + will(returnValue(Map.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_URL_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_TEXT_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getPropertyValues(SarifValidationHandler.SARIF_HELP_MARKDOWN_KEY); + will(returnValue(Set.of())); + allowing(constraintA).getInternalIdentifier(); + will(returnValue("test-constraint-id")); + + allowing(node).getLocation(); + will(returnValue(location)); + allowing(node).getBaseUri(); + will(returnValue(sourceFile.toUri())); + allowing(node).getMetapath(); + will(returnValue("/node/child")); + + allowing(location).getLine(); + will(returnValue(42)); + allowing(location).getColumn(); + will(returnValue(0)); + allowing(location).getByteOffset(); + will(returnValue(1024L)); + allowing(location).getCharOffset(); + will(returnValue(2048L)); + } + }); + + // Populate timing data + TimingCollector collector = new TimingCollector(); + URI docUri = ObjectUtils.notNull(sourceFile.toUri()); + + collector.beforeValidation(docUri); + collector.beforePhase(ValidationPhase.SCHEMA_VALIDATION); + busyWait(); + collector.afterPhase(ValidationPhase.SCHEMA_VALIDATION); + collector.beforePhase(ValidationPhase.CONSTRAINT_VALIDATION); + collector.beforeConstraintEvaluation(constraintA, node); + busyWait(); + collector.afterConstraintEvaluation(constraintA, node); + collector.afterPhase(ValidationPhase.CONSTRAINT_VALIDATION); + collector.afterValidation(docUri); + + SarifValidationHandler handler + = new SarifValidationHandler(ObjectUtils.notNull(sourceFile.toUri()), versionInfo); + handler.setTimingCollector(collector); + + handler.addFinding(ConstraintValidationFinding.builder(constraintA, node) + .kind(IValidationFinding.Kind.FAIL) + .build()); + + String sarifOutput = handler.writeToString(IBindingContext.newInstance()); + + // Validate against SARIF 2.1.0 schema + Path sarifSchema = Paths.get("modules/sarif/sarif-schema-2.1.0.json"); + + try (Reader schemaReader = Files.newBufferedReader(sarifSchema, StandardCharsets.UTF_8)) { + JsonNode schemaNode = new OrgJsonNode(new JSONObject(new JSONTokener(schemaReader))); + JsonNode instanceNode = new OrgJsonNode(new JSONObject(sarifOutput)); + + Validator.Result result = new ValidatorFactory() + .withJsonNodeFactory(new OrgJsonNode.Factory()) + .withDialect(new Dialects.Draft2020Dialect()) + .validate(schemaNode, instanceNode); + StringJoiner sj = new StringJoiner("\n"); + for (dev.harrel.jsonschema.Error finding : result.getErrors()) { + sj.add(String.format("[%s]%s %s for schema '%s'", + finding.getInstanceLocation(), + finding.getKeyword() == null ? "" : " " + finding.getKeyword() + ":", + finding.getError(), + finding.getSchemaLocation())); + } + assertTrue(result.isValid(), + () -> "SARIF output with timing failed schema validation. Errors:\n" + sj.toString()); + } + } + + /** + * A brief busy-wait to ensure System.nanoTime() advances measurably. + */ + @SuppressWarnings("PMD.EmptyWhileStmt") + private static void busyWait() { + long start = System.nanoTime(); + while (System.nanoTime() - start < 1_000) { + // spin until at least 1 microsecond has elapsed + } + } +} diff --git a/databind/src/main/java/dev/metaschema/databind/IBindingContext.java b/databind/src/main/java/dev/metaschema/databind/IBindingContext.java index 512646c1e7..aaaf3bc5c5 100644 --- a/databind/src/main/java/dev/metaschema/databind/IBindingContext.java +++ b/databind/src/main/java/dev/metaschema/databind/IBindingContext.java @@ -45,7 +45,9 @@ import dev.metaschema.core.model.constraint.IConstraintSet; import dev.metaschema.core.model.constraint.IConstraintValidationHandler; import dev.metaschema.core.model.constraint.IConstraintValidator; -import dev.metaschema.core.model.constraint.ParallelValidationConfig; +import dev.metaschema.core.model.constraint.NoOpValidationEventListener; +import dev.metaschema.core.model.constraint.ValidationConfig; +import dev.metaschema.core.model.constraint.ValidationEventListener; import dev.metaschema.core.model.constraint.ValidationFeature; import dev.metaschema.core.model.validation.AggregateValidationResult; import dev.metaschema.core.model.validation.IValidationResult; @@ -495,11 +497,19 @@ default IConstraintValidator newValidator( int threadCount = config != null ? config.get(ValidationFeature.PARALLEL_THREADS) : ValidationFeature.PARALLEL_THREADS.getDefault(); - ParallelValidationConfig parallelConfig = threadCount > 1 - ? ParallelValidationConfig.withThreads(threadCount) - : ParallelValidationConfig.SEQUENTIAL; + ValidationConfig validationConfig = threadCount > 1 + ? ValidationConfig.withThreads(threadCount) + : ValidationConfig.SEQUENTIAL; + + // Apply event listener if configured + ValidationEventListener listener = config != null + ? config.get(ValidationFeature.EVENT_LISTENER) + : null; + if (listener != null && listener != NoOpValidationEventListener.INSTANCE) { + validationConfig = validationConfig.withListener(listener); + } - DefaultConstraintValidator retval = new DefaultConstraintValidator(handler, parallelConfig); + DefaultConstraintValidator retval = new DefaultConstraintValidator(handler, validationConfig); if (config != null) { retval.applyConfiguration(config); } diff --git a/databind/src/main/java/dev/metaschema/databind/codegen/typeinfo/AnyInstanceTypeInfoImpl.java b/databind/src/main/java/dev/metaschema/databind/codegen/typeinfo/AnyInstanceTypeInfoImpl.java index e64cf2354c..0b698185c1 100644 --- a/databind/src/main/java/dev/metaschema/databind/codegen/typeinfo/AnyInstanceTypeInfoImpl.java +++ b/databind/src/main/java/dev/metaschema/databind/codegen/typeinfo/AnyInstanceTypeInfoImpl.java @@ -7,6 +7,7 @@ import com.squareup.javapoet.ClassName; import com.squareup.javapoet.FieldSpec; +import com.squareup.javapoet.MethodSpec; import com.squareup.javapoet.TypeName; import com.squareup.javapoet.TypeSpec; @@ -62,6 +63,26 @@ public TypeName getJavaFieldType() { return ClassName.get(IAnyContent.class); } + @Override + public void buildFieldJavadoc(FieldSpec.Builder builder) { + builder.addJavadoc("Captures unmodeled content not defined by the Metaschema model.\n"); + } + + @Override + public void buildGetterJavadoc(MethodSpec.Builder builder) { + builder.addJavadoc("Get the unmodeled content.\n"); + builder.addJavadoc("\n"); + builder.addJavadoc("@return the unmodeled content, or {@code null} if not set\n"); + } + + @Override + public void buildSetterJavadoc(MethodSpec.Builder builder, String paramName) { + builder.addJavadoc("Set the unmodeled content.\n"); + builder.addJavadoc("\n"); + builder.addJavadoc("@param $L\n", paramName); + builder.addJavadoc(" the unmodeled content to set\n"); + } + @Override public Set buildField( TypeSpec.Builder typeBuilder, diff --git a/metaschema-cli/pom.xml b/metaschema-cli/pom.xml index c3f08ca1fd..98cad5f550 100644 --- a/metaschema-cli/pom.xml +++ b/metaschema-cli/pom.xml @@ -63,7 +63,12 @@ org.assertj assertj-core test - + + + dev.harrel + json-schema + test + diff --git a/metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java b/metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java index c4aa717596..c15177ce5e 100644 --- a/metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java +++ b/metaschema-cli/src/main/java/dev/metaschema/cli/commands/AbstractValidateContentCommand.java @@ -37,8 +37,10 @@ import dev.metaschema.core.metapath.format.PathFormatSelection; import dev.metaschema.core.model.IModule; import dev.metaschema.core.model.MetaschemaException; +import dev.metaschema.core.model.constraint.CompositeValidationEventListener; import dev.metaschema.core.model.constraint.ConstraintValidationException; import dev.metaschema.core.model.constraint.IConstraintSet; +import dev.metaschema.core.model.constraint.TimingCollector; import dev.metaschema.core.model.constraint.ValidationFeature; import dev.metaschema.core.model.validation.AggregateValidationResult; import dev.metaschema.core.model.validation.IValidationResult; @@ -118,6 +120,12 @@ public abstract class AbstractValidateContentCommand .type(Number.class) .desc("number of threads for parallel constraint validation (default: 1, experimental)") .get()); + @NonNull + private static final Option SARIF_TIMING_OPTION = ObjectUtils.notNull( + Option.builder() + .longOpt("sarif-timing") + .desc("include per-constraint and per-phase timing data in SARIF output (requires -o, experimental)") + .get()); @Override public String getName() { @@ -132,6 +140,7 @@ public Collection gatherOptions() { CONSTRAINTS_OPTION, SARIF_OUTPUT_FILE_OPTION, SARIF_INCLUDE_PASS_OPTION, + SARIF_TIMING_OPTION, NO_SCHEMA_VALIDATION_OPTION, NO_CONSTRAINT_VALIDATION_OPTION, PATH_FORMAT_OPTION, @@ -149,6 +158,11 @@ public List getExtraArguments() { protected abstract class AbstractValidationCommandExecutor extends AbstractCommandExecutor { + @Nullable + private TimingCollector timingCollector; + @Nullable + private SarifValidationHandler sarifHandler; + /** * Construct a new command executor. * @@ -291,6 +305,31 @@ private IValidationResult validate( configuration.enableFeature(ValidationFeature.VALIDATE_GENERATE_PASS_FINDINGS); } + // Validate --sarif-timing requires -o + if (commandLine.hasOption(SARIF_TIMING_OPTION) + && !commandLine.hasOption(SARIF_OUTPUT_FILE_OPTION)) { + throw new CommandExecutionException( + ExitCode.INVALID_ARGUMENTS, + "--sarif-timing requires -o for SARIF output"); + } + + // Configure timing collection if requested + if (commandLine.hasOption(SARIF_TIMING_OPTION) && commandLine.hasOption(SARIF_OUTPUT_FILE_OPTION)) { + TimingCollector collector = new TimingCollector(); + this.timingCollector = collector; + + // Create SARIF handler early for per-result timing event delivery + IVersionInfo version = getCallingContext().getCLIProcessor() + .getVersionInfos().get(CLIProcessor.COMMAND_VERSION); + SarifValidationHandler handler + = new SarifValidationHandler(source, version); + this.sarifHandler = handler; + + // Register both listeners as a composite + configuration.set(ValidationFeature.EVENT_LISTENER, + new CompositeValidationEventListener(List.of(collector, handler))); + } + // Configure parallel validation if requested if (commandLine.hasOption(PARALLEL_THREADS_OPTION)) { String threadValue = commandLine.getOptionValue(PARALLEL_THREADS_OPTION); @@ -319,7 +358,18 @@ private IValidationResult validate( // perform constraint validation bindingContext.registerModule(module); // ensure the module is registered - IValidationResult constraintValidationResult = bindingContext.validateWithConstraints(source, configuration); + TimingCollector collector = this.timingCollector; + if (collector != null) { + collector.beforeValidation(source); + } + IValidationResult constraintValidationResult; + try { + constraintValidationResult = bindingContext.validateWithConstraints(source, configuration); + } finally { + if (collector != null) { + collector.afterValidation(source); + } + } validationResult = validationResult == null ? constraintValidationResult : AggregateValidationResult.aggregate(validationResult, constraintValidationResult); @@ -351,15 +401,21 @@ private void handleOutput( if (commandLine.hasOption(SARIF_OUTPUT_FILE_OPTION)) { Path sarifFile = ObjectUtils.notNull(Paths.get(commandLine.getOptionValue(SARIF_OUTPUT_FILE_OPTION))); - IVersionInfo version - = getCallingContext().getCLIProcessor().getVersionInfos().get(CLIProcessor.COMMAND_VERSION); - try { - SarifValidationHandler sarifHandler = new SarifValidationHandler(source, version); + // Use pre-created handler (for per-result timing) or create a new one + SarifValidationHandler handler = this.sarifHandler; + if (handler == null) { + IVersionInfo version = getCallingContext().getCLIProcessor() + .getVersionInfos().get(CLIProcessor.COMMAND_VERSION); + handler = new SarifValidationHandler(source, version); + } + if (timingCollector != null) { + handler.setTimingCollector(timingCollector); + } if (validationResult != null) { - sarifHandler.addFindings(validationResult.getFindings()); + handler.addFindings(validationResult.getFindings()); } - sarifHandler.write(sarifFile, bindingContext); + handler.write(sarifFile, bindingContext); } catch (IOException ex) { throw new CommandExecutionException(ExitCode.IO_ERROR, ex.getLocalizedMessage(), ex); } diff --git a/metaschema-cli/src/main/java/module-info.java b/metaschema-cli/src/main/java/module-info.java index 7e348b101e..201f7caca4 100644 --- a/metaschema-cli/src/main/java/module-info.java +++ b/metaschema-cli/src/main/java/module-info.java @@ -26,6 +26,7 @@ requires nl.talsmasoftware.lazy4j; requires org.apache.commons.cli; + requires org.json; requires org.apache.logging.log4j; requires org.apache.logging.log4j.core; diff --git a/metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java b/metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java index 37c7fa3a95..d289895a7c 100644 --- a/metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java +++ b/metaschema-cli/src/test/java/dev/metaschema/cli/CLITest.java @@ -8,8 +8,13 @@ import static org.assertj.core.api.Assertions.assertThat; import static org.junit.jupiter.api.Assertions.assertAll; import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; +import org.json.JSONArray; +import org.json.JSONObject; +import org.json.JSONTokener; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.parallel.Execution; import org.junit.jupiter.api.parallel.ExecutionMode; @@ -17,12 +22,24 @@ import org.junit.jupiter.params.provider.Arguments; import org.junit.jupiter.params.provider.MethodSource; +import java.io.IOException; import java.io.OutputStream; import java.io.PrintStream; +import java.io.Reader; +import java.nio.charset.StandardCharsets; +import java.nio.file.Files; +import java.nio.file.Path; +import java.nio.file.Paths; import java.util.LinkedList; import java.util.List; +import java.util.StringJoiner; import java.util.stream.Stream; +import dev.harrel.jsonschema.Dialects; +import dev.harrel.jsonschema.JsonNode; +import dev.harrel.jsonschema.Validator; +import dev.harrel.jsonschema.ValidatorFactory; +import dev.harrel.jsonschema.providers.OrgJsonNode; import dev.metaschema.cli.processor.ExitCode; import dev.metaschema.cli.processor.ExitStatus; import edu.umd.cs.findbugs.annotations.NonNull; @@ -267,6 +284,16 @@ private static Stream providesValues() { "--as=json" }, ExitCode.OK, NO_EXCEPTION_CLASS)); + // Test --sarif-timing without -o produces an error + add(Arguments.of( + new String[] { "validate-content", + "-m", + "../databind/src/test/resources/metaschema/simple/metaschema.xml", + "../databind/src/test/resources/metaschema/simple/example.json", + "--as=json", + "--sarif-timing" + }, + ExitCode.INVALID_ARGUMENTS, NO_EXCEPTION_CLASS)); } }; return values.stream(); @@ -327,4 +354,147 @@ void testValidateConstraints() { .contains("This constraint SHOULD be violated if test passes."); } } + + @Test + void testSarifTimingOutput() throws IOException { + Path sarifOutput = Paths.get("target/test-sarif-timing.sarif"); + + // Use a module with inline let statements and constraints, plus external + // constraints with additional let statements to exercise all timing features + String[] cliArgs = { + "validate-content", + "-m", + "src/test/resources/content/timing-test-module.xml", + "src/test/resources/content/timing-test-content.json", + "--as=json", + "-c", "src/test/resources/content/timing-test-constraints.xml", + "-o", sarifOutput.toString(), + "--sarif-timing", + "--sarif-include-pass", + "--show-stack-trace" + }; + + ExitStatus status = CLI.runCli(NULL_STREAM, cliArgs); + evaluateResult(status, ExitCode.OK, cliArgs); + + // Verify SARIF output file was created and contains timing data + assertTrue(Files.exists(sarifOutput), "SARIF output file should exist"); + + String sarifContent = new String(Files.readAllBytes(sarifOutput), StandardCharsets.UTF_8); + JSONObject sarif = new JSONObject(sarifContent); + + JSONArray runs = sarif.getJSONArray("runs"); + JSONObject run = runs.getJSONObject(0); + + // Verify invocations with timing are present + assertTrue(run.has("invocations"), "Run should have invocations when --sarif-timing is enabled"); + JSONArray invocations = run.getJSONArray("invocations"); + assertEquals(1, invocations.length(), "Should have exactly one invocation"); + + JSONObject invocation = invocations.getJSONObject(0); + assertTrue(invocation.has("startTimeUtc"), "Invocation should have startTimeUtc"); + assertTrue(invocation.has("endTimeUtc"), "Invocation should have endTimeUtc"); + assertTrue(invocation.getBoolean("executionSuccessful"), "executionSuccessful should be true"); + assertTrue(invocation.has("toolExecutionNotifications"), + "Invocation should have toolExecutionNotifications for phase timing"); + + // Verify phase timing notifications exist + JSONArray notifications = invocation.getJSONArray("toolExecutionNotifications"); + assertTrue(notifications.length() > 0, "Should have at least one phase timing notification"); + + // Verify let-statement timing is captured (module has 2 inline lets + + // constraints has 2 external lets) + boolean foundLetTiming = false; + for (int idx = 0; idx < notifications.length(); idx++) { + JSONObject notification = notifications.getJSONObject(idx); + String text = notification.getJSONObject("message").getString("text"); + if (text.startsWith("$") && text.contains(" := ")) { + foundLetTiming = true; + break; + } + } + assertTrue(foundLetTiming, "Should have let-statement timing notifications"); + + // Verify per-result timing on at least one result (using --sarif-include-pass + // since test content passes all constraints) + JSONArray results = run.getJSONArray("results"); + boolean foundPerResultTiming = false; + for (int idx = 0; idx < results.length(); idx++) { + JSONObject result = results.getJSONObject(idx); + if (result.has("properties")) { + JSONObject props = result.getJSONObject("properties"); + if (props.has("timing")) { + foundPerResultTiming = true; + JSONObject timing = props.getJSONObject("timing"); + assertTrue(timing.has("totalMs"), "Per-result timing should have totalMs"); + break; + } + } + } + assertTrue(foundPerResultTiming, + "At least one result should have per-result timing when --sarif-timing is used"); + + // Validate against official SARIF 2.1.0 schema + Path sarifSchema = Paths.get("../databind-modules/modules/sarif/sarif-schema-2.1.0.json"); + + try (Reader schemaReader = Files.newBufferedReader(sarifSchema, StandardCharsets.UTF_8)) { + JsonNode schemaNode = new OrgJsonNode(new JSONObject(new JSONTokener(schemaReader))); + JsonNode instanceNode = new OrgJsonNode(new JSONObject(sarifContent)); + + Validator.Result result = new ValidatorFactory() + .withJsonNodeFactory(new OrgJsonNode.Factory()) + .withDialect(new Dialects.Draft2020Dialect()) + .validate(schemaNode, instanceNode); + StringJoiner sj = new StringJoiner("\n"); + for (dev.harrel.jsonschema.Error finding : result.getErrors()) { + sj.add(String.format("[%s]%s %s for schema '%s'", + finding.getInstanceLocation(), + finding.getKeyword() == null ? "" : " " + finding.getKeyword() + ":", + finding.getError(), + finding.getSchemaLocation())); + } + assertTrue(result.isValid(), + () -> "SARIF timing output failed schema validation. Errors:\n" + sj.toString()); + } + } + + @Test + void testSarifAlwaysOnInvocations() throws IOException { + Path sarifOutput = Paths.get("target/test-sarif-always-on.sarif"); + + // Run CLI with SARIF output but WITHOUT --sarif-timing + String[] cliArgs = { + "validate-content", + "-m", + "src/test/resources/content/timing-test-module.xml", + "src/test/resources/content/timing-test-content.json", + "--as=json", + "-o", sarifOutput.toString(), + "--show-stack-trace" + }; + + ExitStatus status = CLI.runCli(NULL_STREAM, cliArgs); + evaluateResult(status, ExitCode.OK, cliArgs); + + assertTrue(Files.exists(sarifOutput), "SARIF output file should exist"); + + String sarifContent = new String(Files.readAllBytes(sarifOutput), StandardCharsets.UTF_8); + JSONObject sarif = new JSONObject(sarifContent); + + JSONObject run = sarif.getJSONArray("runs").getJSONObject(0); + + // Always-on: invocations should always be present + assertTrue(run.has("invocations"), "Run should always have invocations (always-on timing)"); + JSONArray invocations = run.getJSONArray("invocations"); + assertEquals(1, invocations.length()); + + JSONObject invocation = invocations.getJSONObject(0); + assertTrue(invocation.has("startTimeUtc"), "Invocation should always have startTimeUtc"); + assertTrue(invocation.has("endTimeUtc"), "Invocation should always have endTimeUtc"); + assertTrue(invocation.getBoolean("executionSuccessful")); + + // Without --sarif-timing, should NOT have timing notifications + assertFalse(invocation.has("toolExecutionNotifications"), + "Invocation should not have timing notifications without --sarif-timing"); + } } diff --git a/metaschema-cli/src/test/resources/content/timing-test-constraints.xml b/metaschema-cli/src/test/resources/content/timing-test-constraints.xml new file mode 100644 index 0000000000..59be345001 --- /dev/null +++ b/metaschema-cli/src/test/resources/content/timing-test-constraints.xml @@ -0,0 +1,16 @@ + + + + + + + + + Average score should be positive, was { $avg-score }. + + + + + diff --git a/metaschema-cli/src/test/resources/content/timing-test-content.json b/metaschema-cli/src/test/resources/content/timing-test-content.json new file mode 100644 index 0000000000..498fb5e140 --- /dev/null +++ b/metaschema-cli/src/test/resources/content/timing-test-content.json @@ -0,0 +1,23 @@ +{ + "timing-root": { + "title": "Timing Integration Test", + "value": 42, + "items": [ + { + "id": "item-1", + "name": "First Item", + "score": 85 + }, + { + "id": "item-2", + "name": "Second Item", + "score": 92 + }, + { + "id": "item-3", + "name": "Third Item", + "score": 78 + } + ] + } +} diff --git a/metaschema-cli/src/test/resources/content/timing-test-module.xml b/metaschema-cli/src/test/resources/content/timing-test-module.xml new file mode 100644 index 0000000000..67af347578 --- /dev/null +++ b/metaschema-cli/src/test/resources/content/timing-test-module.xml @@ -0,0 +1,37 @@ + + + Timing Integration Test Module + 0.1.0 + timing-test + https://github.com/metaschema-framework/metaschema-java/test/timing + https://github.com/metaschema-framework/metaschema-java/test/timing + + timing-root + + + + + + + + + + + + + + + + + Expected at least one item, found { $item-count }. + + + + + + + + + diff --git a/pom.xml b/pom.xml index 743774c8c6..93eb3e10bc 100644 --- a/pom.xml +++ b/pom.xml @@ -55,6 +55,7 @@ 4.0.0 2.13.1 20251224 + 1.9.0 2.0.3 2.25.3 2.12.2 @@ -287,6 +288,11 @@ json ${dependency.json.version} + + dev.harrel + json-schema + ${dependency.json-schema.version} + com.github.erosb everit-json-schema diff --git a/src/site/markdown/guides/sarif-output.md.vm b/src/site/markdown/guides/sarif-output.md.vm new file mode 100644 index 0000000000..1014e44e87 --- /dev/null +++ b/src/site/markdown/guides/sarif-output.md.vm @@ -0,0 +1,329 @@ +# SARIF Output + +This guide explains the SARIF (Static Analysis Results Interchange Format) output produced by Metaschema validation tools. + +## Overview + +Metaschema validation can produce results in [SARIF 2.1.0](https://docs.oasis-open.org/sarif/sarif/v2.1.0/sarif-v2.1.0.html) format, a standardized JSON format for expressing the output of static analysis tools. SARIF output enables integration with IDEs, CI/CD pipelines, and other tools that consume SARIF. + +## Generating SARIF Output + +### From the CLI + +Use the `-o` flag on validation commands to write SARIF output: + +```bash +# Validate a module with SARIF output +metaschema-cli validate -o results.sarif schema/metaschema.xml + +# Validate content with SARIF output +metaschema-cli validate-content -m schema/metaschema.xml \ + -o results.sarif data/instance.xml + +# Include passing results +metaschema-cli validate-content -m schema/metaschema.xml \ + -o results.sarif --sarif-include-pass data/instance.xml +``` + +### From Java + +Use `SarifValidationHandler` to build SARIF output programmatically: + +```java +import dev.metaschema.databind.IBindingContext; +import dev.metaschema.modules.sarif.SarifValidationHandler; + +import java.net.URI; +import java.nio.file.Path; + +URI sourceUri = Path.of("data/instance.xml").toUri(); + +SarifValidationHandler sarifHandler = new SarifValidationHandler(sourceUri); + +// Add findings from validation +// (typically wired through the validation pipeline) +sarifHandler.addFinding(finding); + +// Write SARIF to a file +IBindingContext bindingContext = IBindingContext.newInstance(); +sarifHandler.write(Path.of("results.sarif"), bindingContext); + +// Or get SARIF as a string +String sarifJson = sarifHandler.writeToString(bindingContext); +``` + +## Output Structure + +A SARIF document contains one or more *runs*, each representing a single invocation of an analysis tool. Metaschema validation produces a single run with the following structure: + +```json +{ + "version": "2.1.0", + "$schema": "https://docs.oasis-open.org/sarif/sarif/v2.1.0/sarif-v2.1.0.html", + "runs": [ + { + "tool": { + "driver": { + "name": "Metaschema", + "version": "3.0.0-SNAPSHOT", + "rules": [ ... ] + } + }, + "artifacts": [ ... ], + "results": [ ... ] + } + ] +} +``` + +### Tool and Rules + +The `tool.driver.rules` array contains descriptors for each constraint that produced findings: + +```json +{ + "id": "allowed-values-1", + "guid": "a1b2c3d4-...", + "shortDescription": { + "text": "Allowed values constraint" + }, + "fullDescription": { + "text": "...", + "markdown": "..." + } +} +``` + +### Results + +Each validation finding maps to a `result` entry: + +```json +{ + "ruleId": "allowed-values-1", + "ruleIndex": 0, + "guid": "e5f6g7h8-...", + "kind": "fail", + "level": "error", + "message": { + "text": "Value 'unknown' is not allowed for 'status'" + }, + "locations": [ + { + "physicalLocation": { + "artifactLocation": { + "uri": "data/instance.xml", + "index": 0 + }, + "region": { + "startLine": 42, + "startColumn": 10 + } + } + } + ] +} +``` + +**Result kinds:** `notApplicable`, `pass`, `fail`, `review`, `open`, `informational` + +**Result levels:** `none`, `note`, `warning`, `error` + +### Artifacts + +The `artifacts` array lists the files that were analyzed: + +```json +{ + "location": { + "uri": "data/instance.xml", + "index": 0 + } +} +``` + +## Timing Data + +When timing instrumentation is enabled, the SARIF output is enriched with performance data at three levels: invocation (overall and per-phase), rule (per-constraint), and notifications (let-statements). + +### Enabling Timing + +From the CLI: + +```bash +metaschema-cli validate-content -m schema/metaschema.xml \ + --sarif-timing -o results.sarif data/instance.xml +``` + +From Java: + +```java +import dev.metaschema.core.model.constraint.TimingCollector; +import dev.metaschema.modules.sarif.SarifValidationHandler; + +TimingCollector timings = new TimingCollector(); + +// Wire timing into validation (see Validating with Constraints guide) +// ... + +// Set timing data on the SARIF handler +SarifValidationHandler sarifHandler = new SarifValidationHandler(sourceUri); +sarifHandler.setTimingCollector(timings); + +// SARIF output will now include timing data +sarifHandler.write(Path.of("results.sarif"), bindingContext); +``` + +### Invocation Timing + +When timing is enabled, the run includes an `invocations` array with overall timing and per-phase notifications: + +```json +{ + "invocations": [ + { + "startTimeUtc": "2026-02-08T12:00:00.000Z", + "endTimeUtc": "2026-02-08T12:00:01.234Z", + "executionSuccessful": true, + "toolExecutionNotifications": [ + { + "message": { + "text": "Phase: SCHEMA_VALIDATION" + }, + "timeUtc": "2026-02-08T12:00:00.100Z", + "properties": { + "timing": { + "totalMs": 100.123, + "count": 1, + "minMs": 100.123, + "maxMs": 100.123 + } + } + }, + { + "message": { + "text": "Phase: CONSTRAINT_VALIDATION" + }, + "timeUtc": "2026-02-08T12:00:00.500Z", + "properties": { + "timing": { + "totalMs": 400.567, + "count": 1, + "minMs": 400.567, + "maxMs": 400.567 + } + } + }, + { + "message": { + "text": "Phase: FINALIZATION" + }, + "timeUtc": "2026-02-08T12:00:01.000Z", + "properties": { + "timing": { + "totalMs": 234.321, + "count": 1, + "minMs": 234.321, + "maxMs": 234.321 + } + } + } + ] + } + ] +} +``` + +### Rule Timing + +Per-constraint timing is added to each rule's `properties` bag: + +```json +{ + "id": "allowed-values-1", + "guid": "a1b2c3d4-...", + "shortDescription": { "text": "..." }, + "properties": { + "timing": { + "totalMs": 250.321, + "count": 10, + "minMs": 20.123, + "maxMs": 35.456 + } + } +} +``` + +The timing fields for each entry are: + +| Field | Type | Description | +|-------|------|-------------| +| `totalMs` | decimal | Total accumulated time across all evaluations (milliseconds) | +| `count` | integer | Number of times the constraint was evaluated | +| `minMs` | decimal | Shortest single evaluation (milliseconds) | +| `maxMs` | decimal | Longest single evaluation (milliseconds) | + +### Let-Statement Timing + +Let-statement evaluations appear as additional notifications: + +```json +{ + "message": { + "text": "Let: my-variable" + }, + "timeUtc": "2026-02-08T12:00:00.600Z", + "properties": { + "timing": { + "totalMs": 15.789, + "count": 42, + "minMs": 0.123, + "maxMs": 1.456 + } + } +} +``` + +## Extension Mechanism + +Timing data uses the SARIF `properties` bag, which is the standard SARIF 2.1.0 extension mechanism for tool-specific data. The `properties` bag (`propertyBag` in the spec) supports arbitrary key-value pairs and is available on most SARIF objects. + +This approach is fully compliant with the SARIF 2.1.0 specification. Tools that do not understand the `timing` property will ignore it, while timing-aware tools can extract and display the data. + +## Interpreting Timing Results + +### Identifying Hotspots + +Sort constraints by `totalMs` descending to find the most expensive constraints. High `count` combined with high `totalMs` suggests a constraint that is evaluated many times across the document. + +### Phase Analysis + +Compare phase timings to understand where time is spent: + +- **SCHEMA_VALIDATION** - Time spent validating document structure +- **CONSTRAINT_VALIDATION** - Time spent evaluating Metaschema constraints +- **FINALIZATION** - Time spent on cross-document validation and index resolution + +If `CONSTRAINT_VALIDATION` dominates, use per-constraint timing to identify specific hotspots. + +### Parallel Validation + +Combine `--sarif-timing` with `--threads` to measure the impact of parallel execution: + +```bash +# Measure sequential performance +metaschema-cli validate-content -m schema/metaschema.xml \ + --sarif-timing -o sequential.sarif data/large-instance.xml + +# Measure parallel performance +metaschema-cli validate-content -m schema/metaschema.xml \ + --threads 4 --sarif-timing -o parallel.sarif data/large-instance.xml +``` + +Compare the `CONSTRAINT_VALIDATION` phase timing between the two runs. + +## Next Steps + +- [Validating with Constraints](validating-with-constraints.html) - Constraint types and Java validation API +- [Using the CLI](using-the-cli.html) - CLI command reference +- [Architecture](architecture.html) - System architecture and threading model diff --git a/src/site/markdown/guides/using-the-cli.md.vm b/src/site/markdown/guides/using-the-cli.md.vm new file mode 100644 index 0000000000..03f2cd2eea --- /dev/null +++ b/src/site/markdown/guides/using-the-cli.md.vm @@ -0,0 +1,322 @@ +# Using the CLI + +This guide covers the Metaschema command-line interface (CLI) for validating content, generating schemas, converting between formats, and evaluating Metapath expressions. + +## Installation + +Build the CLI from source: + +```bash +mvn install -DskipTests +``` + +The CLI is packaged as an executable jar with dependencies in `metaschema-cli/target/`. You can run it with: + +```bash +java -jar metaschema-cli/target/metaschema-cli-*-metaschema-cli.jar [command] [options] +``` + +For convenience, the examples below use `metaschema-cli` as a shorthand for this command. + +## Commands + +### validate + +Validate that a Metaschema module is well-formed and valid. + +```bash +metaschema-cli validate [options] +``` + +**Arguments:** + +| Argument | Description | +|----------|-------------| +| `metaschema-module` | The Metaschema module file or URL to validate | + +**Options:** + +| Option | Description | +|--------|-------------| +| `-c, --constraint ` | Additional constraint definitions (repeatable) | +| `-o, --output ` | Write SARIF results to the specified file | +| `--sarif-include-pass` | Include passing results in SARIF output | +| `--sarif-timing` | Include per-constraint timing data in SARIF output (requires `-o`) | +| `--disable-schema-validation` | Skip schema validation | +| `--disable-constraint-validation` | Skip constraint validation | +| `--path-format ` | Path format in output: `auto`, `metapath`, `xpath`, `jsonpointer` (default: `auto`) | +| `--threads ` | Number of threads for parallel constraint validation (default: 1) | + +**Examples:** + +```bash +# Validate a Metaschema module +metaschema-cli validate schema/metaschema.xml + +# Validate with SARIF output +metaschema-cli validate schema/metaschema.xml -o results.sarif + +# Validate with timing data in SARIF output +metaschema-cli validate schema/metaschema.xml -o results.sarif --sarif-timing +``` + +### validate-content + +Validate a content instance against a Metaschema module. + +```bash +metaschema-cli validate-content [options] +``` + +**Arguments:** + +| Argument | Description | +|----------|-------------| +| `content-file` | The content instance file or URL to validate | + +**Options:** + +| Option | Description | +|--------|-------------| +| `-m, --metaschema ` | **(Required)** The Metaschema module defining the content | +| `--as ` | Source format: `XML`, `JSON`, or `YAML` (auto-detected if omitted) | +| `-c, --constraint ` | Additional constraint definitions (repeatable) | +| `-o, --output ` | Write SARIF results to the specified file | +| `--sarif-include-pass` | Include passing results in SARIF output | +| `--sarif-timing` | Include per-constraint timing data in SARIF output (requires `-o`) | +| `--disable-schema-validation` | Skip schema validation | +| `--disable-constraint-validation` | Skip constraint validation | +| `--path-format ` | Path format in output: `auto`, `metapath`, `xpath`, `jsonpointer` (default: `auto`) | +| `--threads ` | Number of threads for parallel constraint validation (default: 1) | + +**Examples:** + +```bash +# Validate XML content +metaschema-cli validate-content -m schema/metaschema.xml data/instance.xml + +# Validate JSON content with explicit format +metaschema-cli validate-content -m schema/metaschema.xml --as JSON data/instance.json + +# Validate with parallel constraint processing and SARIF timing output +metaschema-cli validate-content -m schema/metaschema.xml \ + --threads 4 --sarif-timing -o results.sarif data/instance.xml + +# Validate with additional constraints +metaschema-cli validate-content -m schema/metaschema.xml \ + -c extra-constraints.xml data/instance.xml +``` + +### convert + +Convert a content instance from one format to another. + +```bash +metaschema-cli convert [options] [destination-file] +``` + +**Arguments:** + +| Argument | Description | +|----------|-------------| +| `source-file` | The content instance file or URL to convert | +| `destination-file` | Output file (writes to stdout if omitted) | + +**Options:** + +| Option | Description | +|--------|-------------| +| `-m, --metaschema ` | **(Required)** The Metaschema module defining the content | +| `--to ` | **(Required)** Target format: `XML`, `JSON`, or `YAML` | +| `--overwrite` | Overwrite the destination file if it exists | + +**Examples:** + +```bash +# Convert XML to JSON (output to stdout) +metaschema-cli convert -m schema/metaschema.xml --to JSON data/instance.xml + +# Convert XML to JSON (output to file) +metaschema-cli convert -m schema/metaschema.xml --to JSON \ + data/instance.xml output.json --overwrite + +# Convert YAML to XML +metaschema-cli convert -m schema/metaschema.yaml --to XML data/instance.yaml +``` + +### generate-schema + +Generate an XML Schema (XSD) or JSON Schema from a Metaschema module. + +```bash +metaschema-cli generate-schema [options] [destination-file] +``` + +**Arguments:** + +| Argument | Description | +|----------|-------------| +| `metaschema-module` | The Metaschema module file or URL | +| `destination-file` | Output file (writes to stdout if omitted) | + +**Options:** + +| Option | Description | +|--------|-------------| +| `--as ` | **(Required)** Schema format: `XML` (XSD) or `JSON` | +| `--inline-types` | Generate inline type definitions instead of named types | +| `--overwrite` | Overwrite the destination file if it exists | + +**Examples:** + +```bash +# Generate JSON Schema (output to stdout) +metaschema-cli generate-schema --as JSON schema/metaschema.xml + +# Generate XML Schema to file +metaschema-cli generate-schema --as XML schema/metaschema.xml schema.xsd --overwrite + +# Generate JSON Schema with inline types +metaschema-cli generate-schema --as JSON --inline-types schema/metaschema.yaml schema.json +``` + +### generate-diagram + +Generate a Mermaid entity-relationship diagram from a Metaschema module. + +```bash +metaschema-cli generate-diagram [options] [destination-file] +``` + +**Arguments:** + +| Argument | Description | +|----------|-------------| +| `metaschema-module` | The Metaschema module file or URL | +| `destination-file` | Output file (writes to stdout if omitted) | + +**Options:** + +| Option | Description | +|--------|-------------| +| `--overwrite` | Overwrite the destination file if it exists | + +**Examples:** + +```bash +# Generate diagram to stdout +metaschema-cli generate-diagram schema/metaschema.xml + +# Generate diagram to file +metaschema-cli generate-diagram schema/metaschema.yaml diagram.mmd --overwrite +``` + +### metapath eval + +Evaluate a Metapath expression. + +```bash +metaschema-cli metapath eval [options] +``` + +**Options:** + +| Option | Description | +|--------|-------------| +| `-e, --expression ` | **(Required)** Metapath expression to evaluate | +| `-m, --metaschema ` | Metaschema module for context | +| `-i ` | Content instance to evaluate against | + +The command supports three evaluation modes: + +1. **With module and content** - Evaluates the expression against parsed content +2. **With module only** - Evaluates against the Metaschema module itself +3. **Without module** - Limited to expressions that don't require content context + +**Examples:** + +```bash +# Evaluate a standalone expression +metaschema-cli metapath eval -e 'string-length("hello")' + +# Query a content instance +metaschema-cli metapath eval -m schema/metaschema.xml \ + -i data/instance.json -e '//title' + +# Query a Metaschema module +metaschema-cli metapath eval -m schema/metaschema.xml -e '//define-assembly/@name' +``` + +### metapath list-functions + +List all available Metapath functions. + +```bash +metaschema-cli metapath list-functions +``` + +Functions are grouped by namespace (`fn:`, `math:`, `array:`, `map:`) and displayed with their signatures. + +## Validation Options + +### Parallel Constraint Processing + +Use `--threads` to enable parallel constraint evaluation for large documents: + +```bash +metaschema-cli validate-content -m schema/metaschema.xml \ + --threads 4 data/large-instance.xml +``` + +Setting `--threads` to the number of available CPU cores typically provides the best performance for documents with many constraints. + +### SARIF Output + +Use `-o` to write validation results in [SARIF 2.1.0](https://docs.oasis-open.org/sarif/sarif/v2.1.0/sarif-v2.1.0.html) format: + +```bash +metaschema-cli validate-content -m schema/metaschema.xml \ + -o results.sarif data/instance.xml +``` + +SARIF output includes tool information, validation findings with locations, and rule descriptors. See the [SARIF Output](sarif-output.html) guide for details on the output format. + +### SARIF Timing + +Add `--sarif-timing` to include performance instrumentation in SARIF output: + +```bash +metaschema-cli validate-content -m schema/metaschema.xml \ + --sarif-timing -o results.sarif data/instance.xml +``` + +This adds per-constraint, per-phase, and overall timing data to the SARIF output. See the [SARIF Output](sarif-output.html) guide for the timing data format. + +### Path Format + +Control how locations are displayed in validation output: + +| Format | Description | Example | +|--------|-------------|---------| +| `auto` | Auto-detect based on content format (default) | Varies | +| `metapath` | Metapath expressions | `/catalog/metadata/title` | +| `xpath` | XPath for XML content | `/catalog/metadata/title` | +| `jsonpointer` | JSON Pointer (RFC 6901) | `/catalog/metadata/title` | + +### Additional Constraints + +Load external constraint definitions alongside the module's built-in constraints: + +```bash +metaschema-cli validate-content -m schema/metaschema.xml \ + -c organization-rules.xml -c project-rules.xml data/instance.xml +``` + +The `-c` option can be specified multiple times to load multiple constraint files. + +## Next Steps + +- [Validating with Constraints](validating-with-constraints.html) - Java API for constraint validation +- [SARIF Output](sarif-output.html) - Understanding SARIF validation results +- [Executing Metapath](executing-metapath.html) - Metapath expression syntax +- [Generating Schemas](generating-schemas.html) - Schema generation details diff --git a/src/site/markdown/guides/validating-with-constraints.md.vm b/src/site/markdown/guides/validating-with-constraints.md.vm index 5f526b8d8f..357f5c32f6 100644 --- a/src/site/markdown/guides/validating-with-constraints.md.vm +++ b/src/site/markdown/guides/validating-with-constraints.md.vm @@ -208,6 +208,210 @@ if (highestSeverity.ordinal() >= Level.ERROR.ordinal()) { } ``` +## Parallel Validation + +Constraint validation can be parallelized using `ValidationConfig`. This is useful for large documents with many constraints. + +### Sequential Execution (Default) + +By default, constraints are evaluated sequentially: + +```java +import dev.metaschema.core.model.constraint.DefaultConstraintValidator; +import dev.metaschema.core.model.constraint.ValidationConfig; + +// Sequential is the default - no configuration needed +DefaultConstraintValidator validator = + new DefaultConstraintValidator(handler); + +// Or explicitly use the SEQUENTIAL constant +DefaultConstraintValidator validator = + new DefaultConstraintValidator(handler, ValidationConfig.SEQUENTIAL); +``` + +### Multi-threaded Execution + +Create a configuration with an internal thread pool: + +```java +import dev.metaschema.core.model.constraint.DefaultConstraintValidator; +import dev.metaschema.core.model.constraint.ValidationConfig; + +// Use try-with-resources to ensure thread pool cleanup +try (ValidationConfig config = ValidationConfig.withThreads(4)) { + DefaultConstraintValidator validator = + new DefaultConstraintValidator(handler, config); + + validator.validate(rootItem, dynamicContext); + validator.finalizeValidation(dynamicContext); +} +``` + +### Using an External Executor + +If your application already manages a thread pool, you can provide it directly: + +```java +import dev.metaschema.core.model.constraint.ValidationConfig; + +import java.util.concurrent.ExecutorService; +import java.util.concurrent.ForkJoinPool; + +ExecutorService myPool = new ForkJoinPool(8); + +// The config does NOT shut down your executor on close +try (ValidationConfig config = ValidationConfig.withExecutor(myPool)) { + DefaultConstraintValidator validator = + new DefaultConstraintValidator(handler, config); + validator.validate(rootItem, dynamicContext); + validator.finalizeValidation(dynamicContext); +} + +// Your pool is still running - shut it down when you're done +myPool.shutdown(); +``` + +## Performance Instrumentation + +The validation pipeline supports event-based instrumentation through the `ValidationEventListener` interface. This allows you to measure the performance of individual constraints, let-statements, and validation phases. + +### Collecting Timing Data + +The `TimingCollector` class implements `ValidationEventListener` and records hierarchical timing data: + +```java +import dev.metaschema.core.model.constraint.DefaultConstraintValidator; +import dev.metaschema.core.model.constraint.TimingCollector; +import dev.metaschema.core.model.constraint.TimingRecord; +import dev.metaschema.core.model.constraint.ValidationConfig; +import dev.metaschema.core.model.constraint.ValidationPhase; + +import java.util.Map; + +// Create a timing collector +TimingCollector timings = new TimingCollector(); + +// Wire it into the validation configuration +try (ValidationConfig config = ValidationConfig.withThreads(4) + .withListener(timings)) { + DefaultConstraintValidator validator = + new DefaultConstraintValidator(handler, config); + + validator.validate(rootItem, dynamicContext); + validator.finalizeValidation(dynamicContext); +} + +// Query overall validation timing +TimingRecord overall = timings.getValidationTiming(); +if (overall != null) { + System.out.printf("Total validation: %.3f ms (%d invocations)%n", + overall.getTotalTimeNs() / 1_000_000.0, + overall.getCount()); +} + +// Query per-phase timing +for (Map.Entry entry + : timings.getPhaseTimings().entrySet()) { + TimingRecord record = entry.getValue(); + System.out.printf(" %s: %.3f ms%n", + entry.getKey(), + record.getTotalTimeNs() / 1_000_000.0); +} + +// Find the slowest constraints +timings.getConstraintTimings().entrySet().stream() + .sorted((a, b) -> Long.compare( + b.getValue().getTotalTimeNs(), + a.getValue().getTotalTimeNs())) + .limit(10) + .forEach(entry -> { + TimingRecord record = entry.getValue(); + System.out.printf(" %s: %.3f ms (%d evals, min=%.3f, max=%.3f)%n", + entry.getKey(), + record.getTotalTimeNs() / 1_000_000.0, + record.getCount(), + record.getMinTimeNs() / 1_000_000.0, + record.getMaxTimeNs() / 1_000_000.0); + }); +``` + +### Validation Phases + +The `ValidationPhase` enum identifies three distinct phases: + +| Phase | Description | +|-------|-------------| +| `SCHEMA_VALIDATION` | Schema validation against XML Schema or JSON Schema | +| `CONSTRAINT_VALIDATION` | Evaluation of Metaschema constraints | +| `FINALIZATION` | Post-validation finalization (cross-document constraints, index resolution) | + +### Custom Event Listeners + +Implement `ValidationEventListener` to create custom instrumentation: + +```java +import dev.metaschema.core.model.constraint.ValidationEventListener; +import dev.metaschema.core.model.constraint.ValidationPhase; +import dev.metaschema.core.model.constraint.IConstraint; +import dev.metaschema.core.model.constraint.ILet; +import dev.metaschema.core.metapath.item.node.INodeItem; + +import java.net.URI; + +public class LoggingEventListener implements ValidationEventListener { + + @Override + public void beforeValidation(URI document) { + System.out.println("Starting validation of " + document); + } + + @Override + public void afterValidation(URI document) { + System.out.println("Finished validation of " + document); + } + + @Override + public void beforePhase(ValidationPhase phase) { + System.out.println(" Entering phase: " + phase); + } + + @Override + public void afterPhase(ValidationPhase phase) { + System.out.println(" Completed phase: " + phase); + } + + @Override + public void beforeConstraintEvaluation(IConstraint constraint, + INodeItem target) { + // Called for each constraint evaluation + } + + @Override + public void afterConstraintEvaluation(IConstraint constraint, + INodeItem target) { + // Called after each constraint evaluation + } + + @Override + public void beforeLetEvaluation(ILet let) { + // Called before each let-statement binding + } + + @Override + public void afterLetEvaluation(ILet let) { + // Called after each let-statement binding + } +} +``` + +### Zero Overhead When Disabled + +When no listener is configured, `ValidationConfig` uses `NoOpValidationEventListener`, which provides empty implementations for all callbacks. This ensures zero overhead from instrumentation when timing is not needed. + +### SARIF Timing Output + +Timing data can be included in SARIF output using the `--sarif-timing` CLI flag or by programmatically setting a `TimingCollector` on `SarifValidationHandler`. See the [SARIF Output](sarif-output.html) guide for details. + ## Constraint Levels Control validation behavior with levels: @@ -310,10 +514,6 @@ Define constraints in separate files: 4. **Handle all severities** - Don't ignore warnings 5. **Test constraints** - Validate with known-bad data -## Constraint Validation Status - -> **Note:** Metaschema constraint validation is experimental in some areas. Schema-level validation (structure, types) is stable. Advanced constraint types may have limitations. - ## Next Steps Continue learning about the Metaschema Java Tools with these related guides: @@ -321,3 +521,5 @@ Continue learning about the Metaschema Java Tools with these related guides: - [Executing Metapath](executing-metapath.html) - Write constraint expressions - [Reading & Writing Data](reading-writing-data.html) - Load data for validation - [Generating Schemas](generating-schemas.html) - Generate schema validators +- [SARIF Output](sarif-output.html) - Machine-readable validation results with timing +- [Using the CLI](using-the-cli.html) - Command-line validation diff --git a/src/site/site.xml b/src/site/site.xml index f2a533c27f..f8f519c1d9 100644 --- a/src/site/site.xml +++ b/src/site/site.xml @@ -121,7 +121,9 @@ + +