OpenTelemetry: metrics for signature verification duration

CHANGES.md

@@ -41,6 +41,21 @@ To be released.
     attributes, and `TraceActivityRecord.activityJson` is present only when the
     span event includes full activity JSON.  [[#316], [#619], [#755]]
 
+ -  Added two OpenTelemetry histograms for signature verification:
+    `activitypub.signature.verification.duration` measures end-to-end
+    verification time for HTTP Signatures, Linked Data Signatures, and
+    Object Integrity Proofs (including local key lookup and remote key
+    fetches), and `activitypub.signature.key_fetch.duration` measures
+    public key lookup duration separately so operators can isolate
+    non-fetch verification work.  Both instruments carry
+    `activitypub.signature.kind` (`http`, `linked_data`, or
+    `object_integrity`) and bounded result attributes; the verification
+    histogram additionally carries spec-bounded
+    `http_signatures.algorithm`, `ld_signatures.type`, or
+    `object_integrity_proofs.cryptosuite` when known, plus
+    `http_signatures.failure_reason` on rejected HTTP rows.
+    [[#316], [#737], [#769]]
+
  -  Added OpenTelemetry HTTP server metrics for inbound requests handled by
     `Federation.fetch()`: `fedify.http.server.request.count` (Counter) and
     `fedify.http.server.request.duration` (Histogram).  Both instruments carry
@@ -80,13 +95,15 @@ To be released.
 [#619]: https://github.com/fedify-dev/fedify/issues/619
 [#735]: https://github.com/fedify-dev/fedify/issues/735
 [#736]: https://github.com/fedify-dev/fedify/issues/736
+[#737]: https://github.com/fedify-dev/fedify/issues/737
 [#740]: https://github.com/fedify-dev/fedify/issues/740
 [#748]: https://github.com/fedify-dev/fedify/pull/748
 [#752]: https://github.com/fedify-dev/fedify/issues/752
 [#753]: https://github.com/fedify-dev/fedify/pull/753
 [#755]: https://github.com/fedify-dev/fedify/pull/755
 [#757]: https://github.com/fedify-dev/fedify/pull/757
 [#759]: https://github.com/fedify-dev/fedify/pull/759
+[#769]: https://github.com/fedify-dev/fedify/pull/769
 
 ### @fedify/fixture
 

docs/manual/opentelemetry.md

@@ -296,21 +296,23 @@ Instrumented metrics
 
 Fedify records the following OpenTelemetry metrics:
 
-| Metric name                                  | Instrument    | Unit        | Description                                                     |
-| -------------------------------------------- | ------------- | ----------- | --------------------------------------------------------------- |
-| `activitypub.delivery.sent`                  | Counter       | `{attempt}` | Counts outgoing ActivityPub delivery attempts.                  |
-| `activitypub.delivery.permanent_failure`     | Counter       | `{failure}` | Counts outgoing deliveries abandoned as permanent failures.     |
-| `activitypub.delivery.duration`              | Histogram     | `ms`        | Measures outgoing ActivityPub delivery attempt duration.        |
-| `activitypub.inbox.processing_duration`      | Histogram     | `ms`        | Measures inbox listener processing duration.                    |
-| `activitypub.signature.verification_failure` | Counter       | `{failure}` | Counts failed signature verification for inbox requests.        |
-| `fedify.http.server.request.count`           | Counter       | `{request}` | Counts inbound HTTP requests handled by `Federation.fetch()`.   |
-| `fedify.http.server.request.duration`        | Histogram     | `ms`        | Measures inbound HTTP request duration in `Federation.fetch()`. |
-| `fedify.queue.task.enqueued`                 | Counter       | `{task}`    | Counts inbox, outbox, and fanout tasks Fedify enqueued.         |
-| `fedify.queue.task.started`                  | Counter       | `{task}`    | Counts queue tasks Fedify began processing as a worker.         |
-| `fedify.queue.task.completed`                | Counter       | `{task}`    | Counts queue tasks Fedify finished processing without throwing. |
-| `fedify.queue.task.failed`                   | Counter       | `{task}`    | Counts queue tasks Fedify abandoned because processing threw.   |
-| `fedify.queue.task.duration`                 | Histogram     | `ms`        | Measures queue task processing duration in Fedify workers.      |
-| `fedify.queue.task.in_flight`                | UpDownCounter | `{task}`    | Tracks queue tasks currently in flight in this Fedify process.  |
+| Metric name                                   | Instrument    | Unit        | Description                                                                                     |
+| --------------------------------------------- | ------------- | ----------- | ----------------------------------------------------------------------------------------------- |
+| `activitypub.delivery.sent`                   | Counter       | `{attempt}` | Counts outgoing ActivityPub delivery attempts.                                                  |
+| `activitypub.delivery.permanent_failure`      | Counter       | `{failure}` | Counts outgoing deliveries abandoned as permanent failures.                                     |
+| `activitypub.delivery.duration`               | Histogram     | `ms`        | Measures outgoing ActivityPub delivery attempt duration.                                        |
+| `activitypub.inbox.processing_duration`       | Histogram     | `ms`        | Measures inbox listener processing duration.                                                    |
+| `activitypub.signature.verification_failure`  | Counter       | `{failure}` | Counts failed signature verification for inbox requests.                                        |
+| `activitypub.signature.verification.duration` | Histogram     | `ms`        | Measures signature verification duration across HTTP, Linked Data, and Object Integrity Proofs. |
+| `activitypub.signature.key_fetch.duration`    | Histogram     | `ms`        | Measures public key lookup duration during signature verification.                              |
+| `fedify.http.server.request.count`            | Counter       | `{request}` | Counts inbound HTTP requests handled by `Federation.fetch()`.                                   |
+| `fedify.http.server.request.duration`         | Histogram     | `ms`        | Measures inbound HTTP request duration in `Federation.fetch()`.                                 |
+| `fedify.queue.task.enqueued`                  | Counter       | `{task}`    | Counts inbox, outbox, and fanout tasks Fedify enqueued.                                         |
+| `fedify.queue.task.started`                   | Counter       | `{task}`    | Counts queue tasks Fedify began processing as a worker.                                         |
+| `fedify.queue.task.completed`                 | Counter       | `{task}`    | Counts queue tasks Fedify finished processing without throwing.                                 |
+| `fedify.queue.task.failed`                    | Counter       | `{task}`    | Counts queue tasks Fedify abandoned because processing threw.                                   |
+| `fedify.queue.task.duration`                  | Histogram     | `ms`        | Measures queue task processing duration in Fedify workers.                                      |
+| `fedify.queue.task.in_flight`                 | UpDownCounter | `{task}`    | Tracks queue tasks currently in flight in this Fedify process.                                  |
 
 ### Metric attributes
 
@@ -332,6 +334,81 @@ Fedify records the following OpenTelemetry metrics:
 :   `activitypub.verification.failure_reason`, plus
     `activitypub.remote.host` when the failed signature includes a key ID.
 
+`activitypub.signature.verification.duration`
+:   `activitypub.signature.kind` is always present and is one of `http`,
+    `linked_data`, or `object_integrity`.  `activitypub.signature.result` is
+    always present and is one of:
+
+     -  `verified`: the signature was checked and accepted.
+     -  `rejected`: the signature was checked and refused (bad signature,
+        key fetch failure, owner mismatch, etc.).
+     -  `missing`: no signature was present.  Only `http` and `linked_data`
+        produce this value; `object_integrity` does not, because the caller
+        decides whether to invoke proof verification at all.
+     -  `error`: verification threw an unexpected error.
+
+    The duration covers the full verification path Fedify performs,
+    *including* local key lookup and remote key fetches; the separate
+    `activitypub.signature.key_fetch.duration` histogram lets operators
+    subtract key lookup latency from the total to isolate the rest of the
+    verification work (canonicalization, hashing, attribution and owner
+    checks, cryptographic verification, etc.).  Direct calls to
+    `verifyRequest()` / `verifyRequestDetailed()`, `verifyJsonLd()`, and
+    `verifyProof()` each emit exactly one measurement, even when the
+    implementation retries internally after a cache mismatch.  Wrappers
+    such as `verifyObject()` emit one measurement per inner `verifyProof()`
+    call (and none when the object has no proofs); higher-level inbox
+    handling can perform several verification attempts in series.
+
+    Kind-specific optional attributes are recorded only when the value
+    matches a small, spec-bounded set, to keep cardinality safe even when
+    attacker-supplied JSON-LD or signature headers reach the verifier:
+
+     -  `http_signatures.algorithm` (HTTP only) is recorded only when the
+        parsed algorithm value is one of `rsa-sha1`, `rsa-sha256`,
+        `rsa-sha512`, `ecdsa-sha256`, `ecdsa-sha384`, `ecdsa-sha512`,
+        `ed25519`, or `hs2019` (draft-cavage) or one of the keys of the
+        RFC 9421 algorithm map (`rsa-v1_5-sha256`, `rsa-v1_5-sha512`,
+        `rsa-pss-sha512`, `ecdsa-p256-sha256`, `ecdsa-p384-sha384`,
+        `ed25519`).
+     -  `http_signatures.failure_reason` (HTTP only, on `rejected` rows)
+        is one of `invalidSignature` or `keyFetchError`.  HTTP requests
+        with no signature header are reported as
+        `activitypub.signature.result=missing` and do not carry a
+        `http_signatures.failure_reason`.
+     -  `ld_signatures.type` (Linked Data only) is recorded only for the
+        spec-supported `RsaSignature2017` type.
+     -  `object_integrity_proofs.cryptosuite` (Object Integrity Proofs
+        only) is recorded only for the spec-supported `eddsa-jcs-2022`
+        cryptosuite.
+
+    Key IDs, actor IDs, request URLs, and object IDs are deliberately
+    excluded from this histogram.  They remain on the corresponding spans
+    (`http_signatures.verify`, `ld_signatures.verify`,
+    `object_integrity_proofs.verify`) for trace-level investigation.
+
+`activitypub.signature.key_fetch.duration`
+:   `activitypub.signature.kind` is always present (same values as above).
+    `activitypub.signature.key_fetch.result` is always present and is one
+    of:
+
+     -  `hit`: the public key was served by the configured `KeyCache`
+        (which may itself be backed by a remote store such as Redis or a
+        database; the measurement reflects whatever round trip that
+        backend incurs).
+     -  `fetched`: the key was not in the cache and was loaded through
+        the document loader, returning a usable key.  This typically
+        corresponds to a network fetch, but a custom document loader
+        that serves from a local store will also fall in this bucket.
+     -  `error`: no usable key came back (HTTP failure, invalid response
+        body, cached negative entry, thrown exception, etc.).
+
+    Unlike `activitypub.signature.verification.duration`, this histogram
+    is recorded *per fetch attempt*: a verification that retries after a
+    cache mismatch emits two key fetch measurements (typically one `hit`
+    for the stale attempt and one `fetched` for the freshly fetched retry)
+    alongside the single verification measurement that covers both.
+
 `fedify.http.server.request.count` and `fedify.http.server.request.duration`
 :   `http.request.method` and `fedify.endpoint` are always present.
     `http.request.method` is normalized to one of the standard HTTP methods

packages/fedify/src/federation/handler.ts

@@ -842,6 +842,7 @@ async function handleInboxInternal<TContextData>(
     signatureTimeWindow,
     skipSignatureVerification,
     inboxChallengePolicy,
+    meterProvider,
     tracerProvider,
   } = parameters;
   const logger = getLogger(["fedify", "federation", "inbox"]);
@@ -913,6 +914,7 @@ async function handleInboxInternal<TContextData>(
       contextLoader: ctx.contextLoader,
       documentLoader: ctx.documentLoader,
       keyCache,
+      meterProvider,
       tracerProvider,
     });
   } catch (error) {
@@ -942,6 +944,7 @@ async function handleInboxInternal<TContextData>(
         contextLoader: ctx.contextLoader,
         documentLoader: ctx.documentLoader,
         keyCache,
+        meterProvider,
         tracerProvider,
       });
     } catch (error) {
@@ -991,6 +994,7 @@ async function handleInboxInternal<TContextData>(
         documentLoader: ctx.documentLoader,
         timeWindow: signatureTimeWindow,
         keyCache,
+        meterProvider,
         tracerProvider,
       });
       if (verification.verified === false) {

packages/fedify/src/federation/metrics.ts

@@ -31,10 +31,85 @@ export interface QueueTaskCommonAttributes {
   activityType?: string;
 }
 
+/**
+ * The kind of ActivityPub signature verified, used as the
+ * `activitypub.signature.kind` metric attribute.
+ * @since 2.3.0
+ */
+export type SignatureVerificationKind =
+  | "http"
+  | "linked_data"
+  | "object_integrity";
+
+/**
+ * The terminal classification of a signature verification attempt, used as
+ * the `activitypub.signature.result` metric attribute.
+ *
+ *  -  `verified`: the signature was checked and accepted.
+ *  -  `rejected`: the signature was checked and refused (bad signature, key
+ *     fetch failure, owner mismatch, etc.).
+ *  -  `missing`: no signature was present.  Only HTTP Signatures and Linked
+ *     Data Signatures distinguish this from `rejected`; Object Integrity
+ *     Proofs never carry this value because callers decide whether to invoke
+ *     {@link import("../sig/proof.ts").verifyProof} at all.
+ *  -  `error`: verification threw an unexpected error.
+ * @since 2.3.0
+ */
+export type SignatureVerificationResult =
+  | "verified"
+  | "rejected"
+  | "missing"
+  | "error";
+
+/**
+ * The terminal classification of a public key fetch performed as part of
+ * signature verification, used as the
+ * `activitypub.signature.key_fetch.result` metric attribute.
+ *
+ *  -  `hit`: the public key was served by the configured `KeyCache`.  The
+ *     `KeyCache` itself may be backed by a remote store such as Redis or a
+ *     database, in which case the measurement reflects whatever round trip
+ *     that backend incurs.
+ *  -  `fetched`: the public key was not in the cache and was loaded
+ *     through the document loader, returning a usable key.  This typically
+ *     corresponds to a network fetch, but a custom document loader that
+ *     serves from a local store will also fall in this bucket.
+ *  -  `error`: the fetch attempt returned no usable key (HTTP failure,
+ *     invalid response body, cached negative entry, thrown exception,
+ *     etc.).
+ * @since 2.3.0
+ */
+export type SignatureKeyFetchResult = "hit" | "fetched" | "error";
+
+/**
+ * Optional attributes recorded alongside an
+ * `activitypub.signature.verification.duration` measurement.  Each field is
+ * scoped to the matching signature kind and is omitted when its value is not
+ * available; values are expected to come from small, spec-bounded sets so
+ * they do not inflate metric cardinality.
+ * @since 2.3.0
+ */
+export interface SignatureVerificationExtraAttributes {
+  /** `http_signatures.algorithm` (HTTP Signatures only). */
+  algorithm?: string;
+  /** `ld_signatures.type` (Linked Data Signatures only). */
+  ldType?: string;
+  /** `object_integrity_proofs.cryptosuite` (Object Integrity Proofs only). */
+  cryptosuite?: string;
+  /**
+   * `http_signatures.failure_reason`, recorded only on HTTP Signature
+   * failures so the histogram can be sliced by reason without exploding
+   * cardinality on success rows.
+   */
+  failureReason?: string;
+}
+
 class FederationMetrics {
   readonly deliverySent: Counter;
   readonly deliveryPermanentFailure: Counter;
   readonly signatureVerificationFailure: Counter;
+  readonly signatureVerificationDuration: Histogram;
+  readonly signatureKeyFetchDuration: Histogram;
   readonly deliveryDuration: Histogram;
   readonly inboxProcessingDuration: Histogram;
   readonly httpServerRequestCount: Counter;
@@ -66,6 +141,24 @@ class FederationMetrics {
         unit: "{failure}",
       },
     );
+    this.signatureVerificationDuration = meter.createHistogram(
+      "activitypub.signature.verification.duration",
+      {
+        description:
+          "Duration of ActivityPub signature verification, including local " +
+          "key lookup and remote key fetches.",
+        unit: "ms",
+      },
+    );
+    this.signatureKeyFetchDuration = meter.createHistogram(
+      "activitypub.signature.key_fetch.duration",
+      {
+        description:
+          "Duration of public key lookup performed during ActivityPub " +
+          "signature verification.",
+        unit: "ms",
+      },
+    );
     this.deliveryDuration = meter.createHistogram(
       "activitypub.delivery.duration",
       {
@@ -208,6 +301,42 @@ class FederationMetrics {
     this.signatureVerificationFailure.add(1, attributes);
   }
 
+  recordSignatureVerificationDuration(
+    durationMs: number,
+    kind: SignatureVerificationKind,
+    result: SignatureVerificationResult,
+    extra: SignatureVerificationExtraAttributes = {},
+  ): void {
+    const attributes: Attributes = {
+      "activitypub.signature.kind": kind,
+      "activitypub.signature.result": result,
+    };
+    if (extra.algorithm != null) {
+      attributes["http_signatures.algorithm"] = extra.algorithm;
+    }
+    if (extra.failureReason != null) {
+      attributes["http_signatures.failure_reason"] = extra.failureReason;
+    }
+    if (extra.ldType != null) {
+      attributes["ld_signatures.type"] = extra.ldType;
+    }
+    if (extra.cryptosuite != null) {
+      attributes["object_integrity_proofs.cryptosuite"] = extra.cryptosuite;
+    }
+    this.signatureVerificationDuration.record(durationMs, attributes);
+  }
+
+  recordSignatureKeyFetchDuration(
+    durationMs: number,
+    kind: SignatureVerificationKind,
+    result: SignatureKeyFetchResult,
+  ): void {
+    this.signatureKeyFetchDuration.record(durationMs, {
+      "activitypub.signature.kind": kind,
+      "activitypub.signature.key_fetch.result": result,
+    });
+  }
+
   recordInboxProcessingDuration(
     activityType: string,
     durationMs: number,

packages/fedify/src/federation/middleware.ts

@@ -2862,6 +2862,7 @@ export class ContextImpl<TContextData> implements Context<TContextData> {
       {
         contextLoader,
         documentLoader: options.documentLoader ?? this.documentLoader,
+        meterProvider: this.meterProvider,
         tracerProvider: options.tracerProvider ?? this.tracerProvider,
         keyCache,
       },
@@ -3089,6 +3090,7 @@ class RequestContextImpl<TContextData> extends ContextImpl<TContextData>
       contextLoader: options.contextLoader ?? this.contextLoader,
       documentLoader: options.documentLoader ?? this.documentLoader,
       timeWindow: this.federation.signatureTimeWindow,
+      meterProvider: this.meterProvider,
       tracerProvider: options.tracerProvider ?? this.tracerProvider,
     });
   }