---
title: 'Instrumentation'
description: "The library includes built-in timing instrumentation to identify performance bottlenecks. The instrumentation has zero overhead when disabled and provides detailed timing breakdowns when enabled."
navigation:
  icon: 'i-ph-book-open'
seo:
  title: 'Instrumentation'
  description: "The library includes built-in timing instrumentation to identify performance bottlenecks. The instrumentation has zero overhead when disabled and provides detailed timing breakdowns when enabled."
---

## Overview


## Quick Start

### Enable Timing

Set the `JSONEVAL_TIMING` environment variable:

```bash
# Linux/macOS
JSONEVAL_TIMING=1 cargo run --release --example basic -- zcc

# Windows PowerShell
$env:JSONEVAL_TIMING=1; cargo run --release --example basic -- zcc
```

### Example Output

```
📊 Timing Summary (JSONEVAL_TIMING enabled)
============================================================
parse schema JSON                       84.96ms
parse context JSON                       3.34µs
parse data JSON                         28.61µs
create instance struct                  83.82ms
parse_schema                           315.57ms
JSONEval::new() [total]                538.59ms
  parse data                            74.26µs
  parse context                          0.76µs
  replace_data_and_context              11.09µs
  purge_cache                           76.16µs
    process batches                    327.53ms
      evaluate_options_templates         5.47µs
      evaluate rules+others            577.61µs
    evaluate_others()                   583.42µs
  evaluate_internal() [total]          328.16ms
evaluate() [total]                     328.34ms
    resolve_layout_elements              0.93ms
    propagate_parent_conditions          0.81ms
  resolve_layout_internal()              1.74ms
get_evaluated_schema()                  11.04ms
============================================================
TOTAL                                    2.42s
```

## API Functions

### Clear Timing Data

::code-group
  ```rust [Rust]
  use json_eval_rs;

  // Clear timing data between scenarios
  json_eval_rs::clear_timing_data();
  ```
  ```csharp [C#]
  // Timing instrumentation is a native Rust debugging feature.
  // It writes directly to stderr when JSONEVAL_TIMING=1 is set.
  ```
  ```typescript [React Native]
  // Timing instrumentation is a native Rust debugging feature.
  // It writes directly to stderr when JSONEVAL_TIMING=1 is set.
  ```
  ```typescript [Web / NodeJS]
  // Timing instrumentation is a native Rust debugging feature.
  // It writes directly to stderr when JSONEVAL_TIMING=1 is set.
  ```
::

### Print Timing Summary

::code-group
  ```rust [Rust]
  use json_eval_rs;

  // Print detailed timing breakdown
  json_eval_rs::print_timing_summary();
  ```
  ```csharp [C#]
  // Timing instrumentation is a native Rust debugging feature.
  // Set JSONEVAL_TIMING=1 environment variable to see output in stderr.
  ```
  ```typescript [React Native]
  // Timing instrumentation is a native Rust debugging feature.
  // Set JSONEVAL_TIMING=1 environment variable to see output in stderr.
  ```
  ```typescript [Web / NodeJS]
  // Timing instrumentation is a native Rust debugging feature.
  // Set JSONEVAL_TIMING=1 environment variable to see output in stderr.
  ```
::

### Complete Example

::code-group
  ```rust [Rust]
  use json_eval_rs::JSONEval;

  fn main() {
      // Clear any previous timing data
      json_eval_rs::clear_timing_data();
      
      // Your code here
      let mut eval = JSONEval::new(schema, None, Some(data))?;
      eval.evaluate(data, None)?;
      let result = eval.get_evaluated_schema(false);
      
      // Print timing summary (only shows output if JSONEVAL_TIMING=1)
      json_eval_rs::print_timing_summary();
  }
  ```
  ```csharp [C#]
  // Timing instrumentation is a native Rust debugging feature.
  // Standard usage triggers native timing logs automatically if JSONEVAL_TIMING=1 is configured in the environment.
  ```
  ```typescript [React Native]
  // Timing instrumentation is a native Rust debugging feature.
  // Standard usage triggers native timing logs automatically if JSONEVAL_TIMING=1 is configured in the environment.
  ```
  ```typescript [Web / NodeJS]
  // Timing instrumentation is a native Rust debugging feature.
  // Standard usage triggers native timing logs automatically if JSONEVAL_TIMING=1 is configured in the environment.
  ```
::

## Instrumented Methods

The following methods are instrumented with timing:

### Initialization
- `JSONEval::new()` - Total initialization time
  - `parse schema JSON` - JSON parsing
  - `parse context JSON` - Context parsing  
  - `parse data JSON` - Data parsing
  - `create instance struct` - Instance creation
  - `parse_schema` - Schema analysis and compilation

### Evaluation
- `evaluate()` - Total evaluation time
  - `parse data` - Data parsing
  - `parse context` - Context parsing
  - `replace_data_and_context` - Data replacement
  - `purge_cache` - Cache invalidation
  - `evaluate_internal()` - Core evaluation logic
    - `process batches` - Batch processing
    - `evaluate_others()` - Other evaluations
      - `evaluate_options_templates` - Template evaluation
      - `evaluate rules+others` - Rules evaluation

### Finalization
- `get_evaluated_schema()` - Schema retrieval
  - `resolve_layout_internal()` - Layout resolution
    - `resolve_layout_elements` - Element resolution
    - `propagate_parent_conditions` - Condition propagation

## Performance Characteristics

### Zero Overhead When Disabled

When `JSONEVAL_TIMING` is not set:
- All timing checks compile to a single boolean check (`is_timing_enabled()`)
- The optimizer inlines and eliminates dead code
- **No measurable performance impact**

### Thread-Local Storage

Timing data is stored in thread-local storage:
- Each thread has its own timing data
- No synchronization overhead
- Safe for multi-threaded applications

### Output Format

Timing output is written to `stderr` using `eprintln!`:
- Doesn't interfere with normal output (`stdout`)
- Can be redirected separately: `2>timing.log`
- Indentation shows call hierarchy

## Interpreting Results

### Understanding Indentation

```
JSONEval::new() [total]      500ms    ← Top-level method
  parse_schema               300ms    ← Sub-operation (2 spaces)
    process batches          200ms    ← Nested operation (4 spaces)
```

### Identifying Bottlenecks

1. Look for methods with high absolute time (>100ms)
2. Look for methods with high relative time (>20% of total)
3. Check nested operations for optimization opportunities

### Example Analysis

```
parse_schema                315ms  ← PRIMARY BOTTLENECK (35%)
process batches             327ms  ← SECONDARY BOTTLENECK (37%)
resolve_layout                2ms  ← Not a concern (<1%)
```

## Integration with External Tools

### Cargo Flamegraph

Combine timing instrumentation with flame graphs:

```bash
# Install flamegraph
cargo install flamegraph

# Generate flame graph with timing
JSONEVAL_TIMING=1 cargo flamegraph --example basic -- zcc
```

### Criterion Benchmarks

Use timing data to validate benchmark improvements:

```rust
use criterion::{black_box, criterion_group, criterion_main, Criterion};
use json_eval_rs::JSONEval;

fn bench_evaluate(c: &mut Criterion) {
    json_eval_rs::clear_timing_data();
    
    c.bench_function("evaluate zcc", |b| {
        b.iter(|| {
            let mut eval = JSONEval::new(schema, None, Some(data)).unwrap();
            eval.evaluate(data, None).unwrap();
            black_box(eval.get_evaluated_schema(false))
        });
    });
    
    json_eval_rs::print_timing_summary();
}
```

## Troubleshooting

### No Timing Output

**Problem**: Running with `JSONEVAL_TIMING=1` but no output appears

**Solutions**:
1. Ensure you're calling `print_timing_summary()`
2. Check that timing code is being executed
3. Verify stderr isn't being redirected

### Unexpected Timing Values

**Problem**: Timing values seem too high or too low

**Causes**:
1. Debug build vs release build (use `--release`)
2. Cold start vs warm start (first run is slower)
3. Background processes affecting CPU
4. File system caching effects

**Best Practice**: Run multiple times and average:
```bash
for i in {1..5}; do JSONEVAL_TIMING=1 cargo run --release --example basic -- zcc; done
```

### Memory Usage

**Problem**: Concerned about memory overhead

**Facts**:
- Timing data stores `(String, Duration)` tuples
- Typical scenario: <100 entries = ~10KB
- Automatically cleared with `clear_timing_data()`
- Thread-local = isolated per thread

## Contributing

To add timing to new methods:

```rust
fn my_method(&self) -> Result<Value, String> {
    time_block!("my_method", {
        // Your code here
        let result = expensive_operation();
        result
    })
}
```

Naming conventions:
- Top-level methods: `method_name()`
- Sub-operations: `  sub_operation` (2 spaces)
- Nested operations: `    nested_op` (4 spaces)

## See Also

- [Cargo Book - Profiling](https://doc.rust-lang.org/cargo/guide/build-cache.html)
- [Rust Performance Book](https://nnethercote.github.io/perf-book/)
