dotnet / dotnet/aspnetcore

Expose per-request start timestamp (or hook) at `BeginRequestProcessing` in Kestrel

Open
#66,336 3 comments 0 reactions 0 assignees View on GitHub
area-networking feature-kestrel feature-request
Dominant language
C#
Stars
38.4k
Forks
10.9k
Avg merge
2d 6h
Merged PRs (30d)
290

Description

### Is there an existing issue for this?

- [x] I have searched the existing issues

- Related discussion (no solution): [dotnet/aspnetcore#23664](https://github.com/dotnet/aspnetcore/discussions/23664) — discusses Kestrel request queue time visibility but does not propose or implement a per-request timestamp feature.

### Is your feature request related to a problem? Please describe the problem.

I am trying to **relatively accurately measure request age in a high-throughput, CPU-intensive service running on Kestrel (self-hosted, .NET 8)** but the earliest per-request timestamp accessible to application code is captured too late in the request lifecycle.

#### Background

Our service previously ran on IIS where we used a custom `IHttpModule` hooking into `BeginRequest` — this fired **before** the ASP.NET pipeline, giving us a timestamp that included IIS queue time. We used this for:

1. **Request timeout enforcement** — comparing `DateTime.UtcNow - requestStartTime` against an allowed processing timeout at ~40 call sites across the service. If a request has aged too long (e.g., >5s), we short-circuit it immediately rather than spending CPU on a response the client has already abandoned.
2. **Queue time telemetry** — logging the delta between request arrival and pipeline entry to monitor server health and detect overload.

#### What's available today in Kestrel

| Approach | When it's set | Limitation |
|----------|--------------|------------|
| `IHttpActivityFeature.Activity.StartTimeUtc` | During `HostingApplicationDiagnostics.BeginRequest()`, inside `HostingApplication.CreateContext()` | Set **after** HTTP parsing and hosting layer setup. Requires `_logger.IsEnabled(LogLevel.Critical)` to be true (usually is, but not guaranteed). |
| First middleware `DateTime.UtcNow` | When middleware pipeline starts executing | Same timing as above — microseconds after `Activity.StartTimeUtc`. |
| Kestrel EventSource `RequestStart` (ETW) | `HttpProtocol.cs` — after `CreateContext()` | Requires an `EventListener` with a per-request correlation dictionary to map ETW events back to `HttpContext`. This is fragile, indirect, and difficult to maintain in production — it's a workaround for something that should be a first-class feature. It also fires **after** `Activity.StartTimeUtc`, so it doesn't even give an earlier timestamp. |

#### The gap

Within Kestrel's internals, `Http1Connection.BeginRequestProcessing()` is the **earliest per-request entry point** — it runs `Reset()` and starts per-request state. However, it's `protected override` on `internal` classes, so application code cannot hook into it or read a timestamp from this stage.

All accessible timestamps are captured **after** `BeginRequestProcessing()` completes and `HostingApplication.CreateContext()` runs. There is no way for application code to get a timestamp from this earlier per-request point.

#### Request lifecycle showing the gap

```
[TCP ACCEPT]
SocketConnectionListener.AcceptAsync()

├─ ConnectionDispatcher: ConnectionQueuedStart() ← Counter++ only
├─ ThreadPool.UnsafeQueueUserWorkItem() ← Connection queued
│ │
│ │ ... ThreadPool scheduling delay ... ← No timestamp
│ │
├─ KestrelConnectionOfT.ExecuteAsync()
│ ├─ ConnectionQueuedStop() ← Counter--
│ ├─ ConnectionStart()
│ │
│ └─ Connection pipeline (TLS, etc.)
│ │
│ └─ HttpProtocol.ProcessRequests()
│ │
│ ├─ BeginRequestProcessing() ← ⭐ EARLIEST PER-REQUEST POINT
│ │ └─ Reset() per-request state (not accessible to app code)
│ │
│ ├─ TryParseRequest() ← Parse HTTP request line + headers
│ │
│ ├─ application.CreateContext(this) ← HttpContext created
│ │ └─ Activity.Start() ← IHttpActivityFeature set here
│ │
│ ├─ KestrelEventSource.RequestStart() ← ETW event (after Activity)
│ │
│ └─ application.ProcessRequestAsync() ← MIDDLEWARE STARTS
│ └─ First middleware ← App code can finally act here
```

#### Why this matters

A single instance of our service handles ~10k–25k RPM and is primarily CPU-bound. Under sustained high CPU load, thread pool starvation occurs and requests age before application code can act on them. Without an accurate early timestamp, our timeout enforcement underestimates true request age, which means:
- We spend CPU processing requests that clients have already timed out on
- Recovery from load spikes is slower because stale requests aren't shed quickly enough
- We lose visibility into how long requests actually waited before being processed

---

### Describe the solution you'd like

Either of the following (in order of preference):

#### Option 1: Per-request timestamp feature (Preferred)

Add a new feature interface that Kestrel populates with the earliest available per-request timestamp:

```csharp
public interface IHttpRequestTimestampFeature
{
///
/// The UTC time when Kestrel first began processing this request,
/// captured as early as possible in the request lifecycle.
///
DateTime RequestStartTimestampUtc { get; }
}
```

Ideally set during or just before `BeginRequestProcessing()` / `Reset()` in `Http1Connection` (and equivalents for HTTP/2 and HTTP/3). This would be before `HostingApplication.CreateContext()` and would give applications the earliest per-request timestamp that Kestrel can provide.

#### Option 2: Hookable callback at BeginRequestProcessing

Expose a way for applications to register a callback that executes at `BeginRequestProcessing()` time — similar to how `IConnectionBuilder` allows middleware on the connection pipeline, but at the per-request level before the hosting layer runs.

For example:

```csharp
options.OnRequestStart = (connectionId, requestId) =>
{
// Record timestamp, populate AsyncLocal, etc.
};
```

---

### Additional context

#### Nice-to-have: Connection Queue Duration

Separately from the per-request timestamp (our primary ask), it would also be valuable to expose the **per-connection queue duration** — the time a connection spends between `ConnectionQueuedStart()` and `ConnectionQueuedStop()` in `ConnectionDispatcher` / `KestrelConnectionOfT`.

Currently, Kestrel tracks `kestrel.queued_connections` as an `UpDownCounter` (how many connections are queued at any moment), but there is no per-connection duration measurement accessible to application code. Under thread pool starvation, this queue time can be significant, and having it available would help services:
- Set practical concurrency limiter values based on observed queue pressure
- Correlate connection queue time with request processing latency
- Alert on sustained queue buildup before it becomes a full outage

This could be exposed as a `kestrel.connection.queue_duration` histogram metric, or as a feature on the connection context.

#### Source references (dotnet/aspnetcore)

- `src/Servers/Kestrel/Core/src/Internal/Http/Http1Connection.cs:838` — `BeginRequestProcessing()` per-request reset
- `src/Servers/Kestrel/Core/src/Internal/Http/HttpProtocol.cs:691` — `CreateContext()` call
- `src/Servers/Kestrel/Core/src/Internal/ConnectionDispatcher.cs:68` — ThreadPool queuing point
- `src/Servers/Kestrel/Core/src/Internal/Infrastructure/KestrelConnectionOfT.cs:53` — First internal timestamp (connection-level only)
- `src/Hosting/Hosting/src/Internal/HostingApplicationDiagnostics.cs:110` — `Activity.Start()` (current earliest accessible timestamp)

#### Environment

- .NET 8 (targeting .NET 9+ as well)
- Kestrel self-hosted (not behind IIS)
- HTTP/1.1 (planning HTTP/2 in future)
- Source analysis based on: `dotnet/aspnetcore` main branch

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.