Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions docs/.vitepress/config.mts
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,7 @@ const sidebar: DefaultTheme.Sidebar = {
{ text: 'Switch Expressions', link: '/reference/switch-expressions' },
{ text: 'Expression Transformers', link: '/reference/expression-transformers' },
{ text: 'Diagnostics & Code Fixes', link: '/reference/diagnostics' },
{ text: 'Telemetry', link: '/reference/telemetry' },
{ text: 'Troubleshooting', link: '/reference/troubleshooting' },
]
}
Expand Down
88 changes: 88 additions & 0 deletions docs/reference/telemetry.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,88 @@
# Telemetry

ExpressiveSharp emits runtime telemetry through the standard .NET diagnostics primitives — `ActivitySource` for distributed traces, `Meter` for metrics, and `EventSource` for previously-silent failure paths. All three share the source name `ExpressiveSharp` (also exposed as the constant `ExpressiveDiagnostics.SourceName`).

Every instrument is **zero-cost when no listener is attached**: counters and activities short-circuit on the no-listener path, and the more expensive observations (node-counting, `MemberInfo.ToString()` for tags) are guarded explicitly.

## Activity (Distributed Tracing)

A single span is emitted from the `ExpressiveSharp` `ActivitySource` (the source's name is also exposed as the constant `ExpressiveDiagnostics.SourceName`):

| Span | Emitted from | Tags |
|------|--------------|------|
| `Expressive.Expand` | `expression.ExpandExpressives()` (and the EF Core / MongoDB query compiler decorators that call into it) | `transformer.count`, `expansion.node_count`, `expansion.duration_ms` |

Because the span runs synchronously inside the EF Core query pipeline, it nests cleanly under EF Core's `Microsoft.EntityFrameworkCore` activity. Trace viewers will show:

```
EF query → Expressive.Expand → SQL execution
```

### OpenTelemetry

```csharp
using var tracerProvider = Sdk.CreateTracerProviderBuilder()
.AddSource("ExpressiveSharp")
.AddSource("Microsoft.EntityFrameworkCore") // optional — nests Expressive.Expand under EF activities
.AddOtlpExporter()
.Build();
```

::: tip
The `expansion.duration_ms` tag is recorded redundantly with the activity's intrinsic duration so consumers that only run a metrics pipeline (no tracer) still get the timing.
:::

## Meter (Metrics)

Five instruments on `Meter("ExpressiveSharp")`:

| Instrument | Type | Unit | Tags | What it tells you |
|------------|------|------|------|-------------------|
| `expressive.cache.hits` | Counter<long> | — | — | The runtime resolver cache served the lookup without computing it again. |
| `expressive.cache.misses` | Counter<long> | — | — | The resolver had to compute the lambda for a member it hadn't seen before. |
| `expressive.reflection_fallback.count` | Counter<long> | — | `member` | The slow reflection-based fallback ran. Used for open-generic class members and generic methods not in the static registry. **Sustained activity here is a perf bug.** |
| `expressive.expansion.node_count` | Histogram<int> | nodes | — | Total expression-tree node count after expansion + transformers. Surfaces members that explode into massive trees and bloat SQL. |
| `expressive.expansion.duration_ms` | Histogram<double> | ms | — | Wall-clock cost of one `ExpandExpressives()` call. |

### Live monitoring with `dotnet-counters`

```sh
dotnet-counters monitor -n MyApp ExpressiveSharp
```

### OpenTelemetry

```csharp
using var meterProvider = Sdk.CreateMeterProviderBuilder()
.AddMeter("ExpressiveSharp")
.AddOtlpExporter()
.Build();
```

::: info
A healthy steady-state has **`cache.hits` ≫ `cache.misses`** after warmup, and **`reflection_fallback.count` should be flat** unless your code uses open-generic `[Expressive]` members. A non-trivial slope on `reflection_fallback.count` means the runtime is paying reflection costs that the static registry could have served — please file an issue with a reproducer.
:::

## EventSource (Failure Diagnostics)

Three events on `EventSource("ExpressiveSharp")`. They surface failure paths that ExpressiveSharp deliberately recovers from but that historically left users debugging by rubber duck.

| Event ID | Name | Level | Payload | When it fires |
|----------|------|-------|---------|---------------|
| `1` | `RegistryInitializationFailed` | Error | `assemblyName`, `exceptionType`, `message` | An assembly's generated `ExpressionRegistry` static constructor threw. The registry is marked inert (no `[ExpressiveFor]` lookups will succeed against it) but the process keeps running. |
| `2` | `HotReloadResetFailed` | Warning | `assemblyName`, `exceptionType`, `message` | A hot-reload edit-and-continue update arrived but invalidating the assembly's expression registry threw. The stale registry stays cached, so the next lookup may return pre-edit lambdas. |
| `3` | `MultipleExpressiveForMappings` | Error | `memberInfoString`, `firstAssembly`, `secondAssembly` | Two different assemblies both registered an `[ExpressiveFor]` mapping for the same member. An `InvalidOperationException` is thrown immediately after; the event fires first so it survives even if the exception is later caught. |

### Collecting with `dotnet-trace`

The most common path. No code changes, no app restart:

```sh
dotnet-trace collect -n MyApp --providers ExpressiveSharp::Verbose
```

Open the resulting `.nettrace` file in [PerfView](https://github.com/microsoft/perfview) or Visual Studio's diagnostic tools to inspect the events.

## Stability

The source name `ExpressiveSharp`, the instrument names, and the EventSource event IDs are part of the public API surface and follow the same stability rules as the rest of ExpressiveSharp. Tags carried on activities and counters may be extended (new tags added) but existing tags will not be renamed within a major version.
17 changes: 17 additions & 0 deletions docs/reference/troubleshooting.md
Original file line number Diff line number Diff line change
Expand Up @@ -322,6 +322,23 @@ public double Total => Price * Quantity;
public double TotalWithTax => Total * (1 + TaxRate); // Total is inlined
```

### How do I see what ExpressiveSharp is doing at runtime?

ExpressiveSharp emits three independent signals on the `ExpressiveSharp` source name — each requires a different out-of-process tool:

```sh
# Failure events (registry static-ctor failures, hot-reload reset failures, [ExpressiveFor] collisions)
dotnet-trace collect -n MyApp --providers ExpressiveSharp::Verbose

# Metrics (cache hit/miss ratios, expansion timings, reflection-fallback rate)
dotnet-counters monitor -n MyApp ExpressiveSharp

# Distributed tracing (the Expressive.Expand activity span) — wire via OpenTelemetry,
# see the Telemetry reference for the AddSource("ExpressiveSharp") snippet.
```

See [Telemetry](./telemetry) for the full instrument and event reference.

### Is ExpressiveSharp EF Core specific?

No. The core `ExpressiveSharp` package works with any LINQ provider or standalone expression tree use case. See [ExpressionPolyfill.Create](../guide/expression-polyfill) and [IExpressiveQueryable](../guide/expressive-queryable) for non-EF-Core usage.
Expand Down
27 changes: 27 additions & 0 deletions src/ExpressiveSharp/Diagnostics/ExpressiveDiagnostics.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
using System.Diagnostics;
using System.Diagnostics.Metrics;

namespace ExpressiveSharp.Diagnostics;

public static class ExpressiveDiagnostics
{
public const string SourceName = "ExpressiveSharp";

internal static readonly ActivitySource ActivitySource = new(SourceName);
internal static readonly Meter Meter = new(SourceName);

internal static readonly Counter<long> CacheHits =
Meter.CreateCounter<long>("expressive.cache.hits");

internal static readonly Counter<long> CacheMisses =
Meter.CreateCounter<long>("expressive.cache.misses");

internal static readonly Counter<long> ReflectionFallback =
Meter.CreateCounter<long>("expressive.reflection_fallback.count");

internal static readonly Histogram<int> ExpansionNodeCount =
Meter.CreateHistogram<int>("expressive.expansion.node_count");

internal static readonly Histogram<double> ExpansionDurationMs =
Meter.CreateHistogram<double>("expressive.expansion.duration_ms", unit: "ms");
}
62 changes: 62 additions & 0 deletions src/ExpressiveSharp/Diagnostics/ExpressiveEventSource.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,62 @@
using System;
using System.Diagnostics.Tracing;
using System.Reflection;

namespace ExpressiveSharp.Diagnostics;

[EventSource(Name = ExpressiveDiagnostics.SourceName)]
internal sealed class ExpressiveEventSource : EventSource
{
public static readonly ExpressiveEventSource Log = new();

private ExpressiveEventSource() { }

[Event(1, Level = EventLevel.Error,
Message = "ExpressiveSharp registry initialization failed for assembly '{0}': {1}: {2}")]
public void RegistryInitializationFailed(string assemblyName, string exceptionType, string message)
=> WriteEvent(1, assemblyName, exceptionType, message);

[NonEvent]
public void RegistryInitializationFailed(Assembly assembly, Exception exception)
{
if (!IsEnabled()) return;
// The caller catches TypeInitializationException, but the actionable cause is the
// static-ctor exception nested inside it — unwrap so consumers see the real failure.
var actual = exception is TypeInitializationException && exception.InnerException is { } inner
? inner : exception;
RegistryInitializationFailed(
assembly.GetName().Name ?? "<unknown>",
actual.GetType().FullName ?? actual.GetType().Name,
actual.Message);
}

[Event(2, Level = EventLevel.Warning,
Message = "ExpressiveSharp hot-reload registry reset failed for assembly '{0}': {1}: {2}")]
public void HotReloadResetFailed(string assemblyName, string exceptionType, string message)
=> WriteEvent(2, assemblyName, exceptionType, message);

[NonEvent]
public void HotReloadResetFailed(Assembly assembly, Exception exception)
{
if (!IsEnabled()) return;
HotReloadResetFailed(
assembly.GetName().Name ?? "<unknown>",
exception.GetType().FullName ?? exception.GetType().Name,
exception.Message);
}

[Event(3, Level = EventLevel.Error,
Message = "Multiple [ExpressiveFor] mappings found for '{0}' in assemblies '{1}' and '{2}'")]
public void MultipleExpressiveForMappings(string memberInfoString, string firstAssembly, string secondAssembly)
=> WriteEvent(3, memberInfoString, firstAssembly, secondAssembly);

[NonEvent]
public void MultipleExpressiveForMappings(MemberInfo memberInfo, Assembly first, Assembly second)
{
if (!IsEnabled()) return;
MultipleExpressiveForMappings(
memberInfo.ToString() ?? memberInfo.Name,
first.GetName().Name ?? "<unknown>",
second.GetName().Name ?? "<unknown>");
}
}
66 changes: 55 additions & 11 deletions src/ExpressiveSharp/Extensions/ExpressionExtensions.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,6 @@
using System.Diagnostics;
using System.Linq.Expressions;
using ExpressiveSharp.Diagnostics;
using ExpressiveSharp.Services;

namespace ExpressiveSharp;
Expand All @@ -16,28 +18,70 @@ public static Expression ExpandExpressives(this Expression expression)
/// Like <see cref="ExpandExpressives(Expression)"/> but uses transformers from the given options.
/// </summary>
public static Expression ExpandExpressives(this Expression expression, ExpressiveOptions options)
{
var expanded = new ExpressiveReplacer(new ExpressiveResolver()).Replace(expression);
var transformers = options.GetTransformers();
foreach (var transformer in transformers)
{
expanded = transformer.Transform(expanded);
}
return expanded;
}
=> ExpandExpressivesCore(expression, options.GetTransformers());

/// <summary>
/// Like <see cref="ExpandExpressives(Expression)"/> but uses the explicitly supplied transformers.
/// </summary>
public static Expression ExpandExpressives(
this Expression expression,
params IExpressionTreeTransformer[] transformers)
=> ExpandExpressivesCore(expression, transformers);

private static Expression ExpandExpressivesCore(
Expression expression,
IReadOnlyList<IExpressionTreeTransformer> transformers)
{
using var activity = ExpressiveDiagnostics.ActivitySource.StartActivity("Expressive.Expand");

var measureDuration = activity is not null || ExpressiveDiagnostics.ExpansionDurationMs.Enabled;
var startTimestamp = measureDuration ? Stopwatch.GetTimestamp() : 0L;

var expanded = new ExpressiveReplacer(new ExpressiveResolver()).Replace(expression);
foreach (var transformer in transformers)
for (var i = 0; i < transformers.Count; i++)
{
expanded = transformers[i].Transform(expanded);
}

if (activity is not null)
{
activity.SetTag("transformer.count", transformers.Count);
}

if (activity is not null || ExpressiveDiagnostics.ExpansionNodeCount.Enabled)
{
var nodeCount = ExpansionNodeCounter.Count(expanded);
ExpressiveDiagnostics.ExpansionNodeCount.Record(nodeCount);
activity?.SetTag("expansion.node_count", nodeCount);
}

if (measureDuration)
{
expanded = transformer.Transform(expanded);
var elapsedMs = Stopwatch.GetElapsedTime(startTimestamp).TotalMilliseconds;
ExpressiveDiagnostics.ExpansionDurationMs.Record(elapsedMs);
activity?.SetTag("expansion.duration_ms", elapsedMs);
}

return expanded;
}

private sealed class ExpansionNodeCounter : ExpressionVisitor
{
private int _count;

public static int Count(Expression? expression)
{
if (expression is null) return 0;
var counter = new ExpansionNodeCounter();
counter.Visit(expression);
return counter._count;
}

public override Expression? Visit(Expression? node)
{
if (node is null) return null;
_count++;
return base.Visit(node);
}
}
}
14 changes: 12 additions & 2 deletions src/ExpressiveSharp/Services/ExpressiveHotReloadHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
using System.Collections.Generic;
using System.Reflection;
using System.Reflection.Metadata;
using ExpressiveSharp.Diagnostics;

[assembly: MetadataUpdateHandler(typeof(ExpressiveSharp.Services.ExpressiveHotReloadHandler))]

Expand Down Expand Up @@ -56,8 +57,17 @@ private static void ResetGeneratedRegistries(IEnumerable<Assembly> assemblies)
var reset = registryType?.GetMethod("ResetMap", BindingFlags.Static | BindingFlags.NonPublic);
if (reset is null) continue;

try { reset.Invoke(null, null); }
catch { /* best-effort; stale registry stays stale */ }
try
{
reset.Invoke(null, null);
}
catch (Exception ex)
{
// Best-effort; stale registry stays stale. Surface via EventSource so
// a hot-reload edit-and-continue failure is no longer silent.
var inner = (ex as TargetInvocationException)?.InnerException ?? ex;
ExpressiveEventSource.Log.HotReloadResetFailed(assembly, inner);
}
}
}
}
Loading
Loading