JWT metrics (#3445)

CHANGELOG.md

@@ -26,6 +26,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
 ### Added
 
 - Added `set_claims_digest()` API to `RpcContext`, see [documentation](https://microsoft.github.io/CCF/main/build_apps/logging_cpp.html#user-defined-claims-in-receipts) on how to use it to attach application-defined claims to transaction receipts.
+- Added a `GET /jwt_metrics` endpoint to monitor attempts and successes of key refresh for each issuer. See [documentation](https://microsoft.github.io/CCF/main/build_apps/auth/jwt.html#extracting-jwt-metrics) on how to use it.
 
 ## [2.0.0-dev7]
 

doc/build_apps/auth/jwt.rst

@@ -180,3 +180,11 @@ Any attempt to add a certificate with mismatching claims in a ``set_jwt_public_s
 
 Some IdPs, like MAA, advertise a mix of SGX and non-SGX signing certificates.
 In this case, ``key_filter`` must be set to ``sgx`` such that only those certificates are stored which contain SGX evidence.
+
+Extracting JWT metrics
+----------------------
+
+CCF tracks the number of JWT queries that were attempted and succeeded. This can be used to identify errors, for example when the number of attempts doesn't match the number of successes.
+Each attempt, for each key on each issuer, is tracked as an attempt, and eventually a success, if the update completes.
+
+To query those numbers, use the RPC API on node endpoint `/jwt_metrics` as described [here](https://microsoft.github.io/CCF/main/operations/operator_rpc_api.html#get--jwt_metrics).

doc/schemas/node_openapi.json

@@ -347,6 +347,21 @@
         ],
         "type": "object"
       },
+      "JWTMetrics": {
+        "properties": {
+          "attempts": {
+            "$ref": "#/components/schemas/uint64"
+          },
+          "successes": {
+            "$ref": "#/components/schemas/uint64"
+          }
+        },
+        "required": [
+          "attempts",
+          "successes"
+        ],
+        "type": "object"
+      },
       "JavaScriptMetrics": {
         "properties": {
           "bytecode_size": {
@@ -699,7 +714,7 @@
   "info": {
     "description": "This API provides public, uncredentialed access to service and node state.",
     "title": "CCF Public Node API",
-    "version": "2.10.0"
+    "version": "2.11.0"
   },
   "openapi": "3.0.0",
   "paths": {
@@ -815,6 +830,22 @@
         }
       }
     },
+    "/jwt_metrics": {
+      "get": {
+        "responses": {
+          "200": {
+            "content": {
+              "application/json": {
+                "schema": {
+                  "$ref": "#/components/schemas/JWTMetrics"
+                }
+              }
+            },
+            "description": "Default response description"
+          }
+        }
+      }
+    },
     "/local_tx": {
       "get": {
         "parameters": [

src/node/jwt_key_auto_refresh.h

@@ -24,6 +24,7 @@ namespace ccf
     std::shared_ptr<enclave::RPCMap> rpc_map;
     crypto::KeyPairPtr node_sign_kp;
     crypto::Pem node_cert;
+    std::atomic_size_t attempts;
 
   public:
     JwtKeyAutoRefresh(
@@ -40,7 +41,8 @@ namespace ccf
       rpcsessions(rpcsessions),
       rpc_map(rpc_map),
       node_sign_kp(node_sign_kp),
-      node_cert(node_cert)
+      node_cert(node_cert),
+      attempts(0)
     {}
 
     struct RefreshTimeMsg
@@ -274,6 +276,9 @@ namespace ccf
       jwt_issuers->foreach([this, &ca_cert_bundles](
                              const JwtIssuer& issuer,
                              const JwtIssuerMetadata& metadata) {
+        // Increment attempts
+        attempts++;
+
         if (!metadata.auto_refresh)
         {
           LOG_DEBUG_FMT(
@@ -335,6 +340,11 @@ namespace ccf
         return true;
       });
     }
-  };
 
+    // Returns a copy of the current attempts
+    size_t get_attempts() const
+    {
+      return attempts.load();
+    }
+  };
 }

src/node/node_state.h

@@ -699,6 +699,11 @@ namespace ccf
         });
     }
 
+    size_t get_jwt_attempts() override
+    {
+      return jwt_key_auto_refresh->get_attempts();
+    }
+
     //
     // funcs in state "readingPublicLedger" or "verifyingSnapshot"
     //

src/node/rpc/node_frontend.h

@@ -66,6 +66,15 @@ namespace ccf
   DECLARE_JSON_TYPE(JavaScriptMetrics);
   DECLARE_JSON_REQUIRED_FIELDS(JavaScriptMetrics, bytecode_size, bytecode_used);
 
+  struct JWTMetrics
+  {
+    size_t attempts;
+    size_t successes;
+  };
+
+  DECLARE_JSON_TYPE(JWTMetrics)
+  DECLARE_JSON_REQUIRED_FIELDS(JWTMetrics, attempts, successes)
+
   struct SetJwtPublicSigningKeys
   {
     std::string issuer;
@@ -312,7 +321,7 @@ namespace ccf
       openapi_info.description =
         "This API provides public, uncredentialed access to service and node "
         "state.";
-      openapi_info.document_version = "2.10.0";
+      openapi_info.document_version = "2.11.0";
     }
 
     void init_handlers() override
@@ -1183,6 +1192,29 @@ namespace ccf
           ccf::endpoints::ExecuteOutsideConsensus::Locally)
         .install();
 
+      auto jwt_metrics = [this](auto&, nlohmann::json&&) {
+        JWTMetrics m;
+        // Attempts are recorded by the key refresh code itself, registering
+        // before each call to each issuer's keys
+        m.attempts = context.get_node_state().get_jwt_attempts();
+        // Success is marked by the fact that the key succeeded and called
+        // our internal "jwt_keys/refresh" endpoint.
+        auto e = fully_qualified_endpoints["/jwt_keys/refresh"][HTTP_POST];
+        auto metric = get_metrics_for_endpoint(e);
+        m.successes = metric.calls - (metric.failures + metric.errors);
+        return m;
+      };
+
+      make_read_only_endpoint(
+        "/jwt_metrics",
+        HTTP_GET,
+        json_read_only_adapter(jwt_metrics),
+        no_auth_required)
+        .set_auto_schema<void, JWTMetrics>()
+        .set_execute_outside_consensus(
+          ccf::endpoints::ExecuteOutsideConsensus::Locally)
+        .install();
+
       auto version = [this](auto&, nlohmann::json&&) {
         GetVersion::Out result;
         result.ccf_version = ccf::ccf_version;

src/node/rpc/node_interface.h

@@ -50,5 +50,6 @@ namespace ccf
       CodeDigest& code_digest) = 0;
     virtual std::optional<kv::Version> get_startup_snapshot_seqno() = 0;
     virtual SessionMetrics get_session_metrics() = 0;
+    virtual size_t get_jwt_attempts() = 0;
   };
 }

src/node/rpc/test/node_stub.h

@@ -121,6 +121,11 @@ namespace ccf
     {
       return {};
     }
+
+    size_t get_jwt_attempts() override
+    {
+      return 0;
+    }
   };
 
   class StubNodeStateCache : public historical::AbstractStateCache

tests/jwt_test.py

@@ -348,6 +348,13 @@ def get_jwt_refresh_endpoint_metrics(network) -> dict:
         return m
 
 
+def get_jwt_metrics(network) -> dict:
+    primary, _ = network.find_nodes()
+    with primary.client(network.consortium.get_any_active_member().local_id) as c:
+        r = c.get("/node/jwt_metrics")
+        return r.body.json()
+
+
 @reqs.description("JWT with auto_refresh enabled")
 def test_jwt_key_auto_refresh(network, args):
     primary, _ = network.find_nodes()
@@ -391,6 +398,11 @@ def test_jwt_key_auto_refresh(network, args):
                 timeout=5,
             )
 
+        LOG.info("Check that JWT refresh has attempts and successes")
+        m = get_jwt_metrics(network)
+        assert m["attempts"] > 0, m["attempts"]
+        assert m["successes"] > 0, m["successes"]
+
         LOG.info("Check that JWT refresh endpoint has no failures")
         m = get_jwt_refresh_endpoint_metrics(network)
         assert m["failures"] == 0, m["failures"]
@@ -407,6 +419,10 @@ def test_jwt_key_auto_refresh(network, args):
 
         with_timeout(check_has_failures, timeout=5)
 
+        LOG.info("Check that JWT refresh has less successes than attempts")
+        m = get_jwt_metrics(network)
+        assert m["attempts"] > m["successes"], m["attempts"]
+
     LOG.info("Restart OpenID endpoint server with new keys")
     kid2 = "the_kid_2"
     issuer.refresh_keys()