From 7add7d5d252f3d2699ae6abb63a9bf6166366d33 Mon Sep 17 00:00:00 2001 From: Hans Zandbelt Date: Fri, 15 Dec 2023 17:06:48 +0100 Subject: [PATCH] 2.4.15rc9: add (and fix) more metrics including provider requests, authorization and cache Signed-off-by: Hans Zandbelt --- ChangeLog | 4 +++ auth_openidc.conf | 7 +++-- configure.ac | 2 +- src/cache/common.c | 24 ++++++++++---- src/metadata.c | 10 +++++- src/metrics.c | 71 ++++++++++++++++++++++++++++++++++-------- src/metrics.h | 38 +++++++++++++++++----- src/mod_auth_openidc.c | 25 +++++++++++++-- src/proto.c | 19 +++++++++-- 9 files changed, 166 insertions(+), 34 deletions(-) diff --git a/ChangeLog b/ChangeLog index 44425795..dd227507 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,7 @@ +12/15/2023 +- add (and fix) more metrics, including provider requests, authorization and cache +- bump to 2.4.15rc9 + 12/14/2023 - add metrics collection capability, configured with OIDCMetricsData and retrieved through OIDCMetricsPublish - bump to 2.4.15rc8 diff --git a/auth_openidc.conf b/auth_openidc.conf index cc873014..349af6a2 100644 --- a/auth_openidc.conf +++ b/auth_openidc.conf @@ -1014,12 +1014,15 @@ # Specify metrics that you wish to collect and keep in shared memory for retrieval. # Supported metrics classes are: # authtype: the authentication handler type split out per AuthType: openid-connect, oauth20, auth-openidc -# redirect_uri: requests to the redirect_uri # authn: authentication request generation and response processing +# authz: authorization errors +# requests: requests to the provider endpoints (metadata retrieval, token request, refresh requests and userinfo requests) # session: existing session handling +# cache: cache read/write/errors +# redirect_uri: requests to the redirect_uri # content: requests to the content handler, split out per types of request (info, metrics, jwks, etc.) # When not defined no metrics will be recorded. -#OIDCMetricsData [ authtype | redirect_uri | authn | session | content ]+ +#OIDCMetricsData [ authtype | authn | authz | requests | session | cache | redirect_uri | content ]+ # Specify the path where metrics are published and can be consumed. # The "format=" parameter can be passed to specify the format of the data. diff --git a/configure.ac b/configure.ac index 4dc09aa9..13e9d496 100644 --- a/configure.ac +++ b/configure.ac @@ -1,4 +1,4 @@ -AC_INIT([mod_auth_openidc],[2.4.15rc8],[hans.zandbelt@openidc.com]) +AC_INIT([mod_auth_openidc],[2.4.15rc9],[hans.zandbelt@openidc.com]) AC_SUBST(NAMEVER, AC_PACKAGE_TARNAME()-AC_PACKAGE_VERSION()) diff --git a/src/cache/common.c b/src/cache/common.c index 9a2363f8..6c74a5c8 100644 --- a/src/cache/common.c +++ b/src/cache/common.c @@ -49,6 +49,8 @@ #include "mod_auth_openidc.h" +#include "metrics.h" + #ifdef AP_NEED_SET_MUTEX_PERMS #include "unixd.h" #endif @@ -279,12 +281,16 @@ apr_byte_t oidc_cache_get(request_rec *r, const char *section, const char *key, s_key = oidc_cache_get_hashed_key(r, s_secret, key); } + OIDC_METRICS_TIMING_START(r, cfg); + /* get the value from the cache */ if (cfg->cache->get(r, section, s_key, &cache_value) == FALSE) { rc = FALSE; goto out; } + OIDC_METRICS_TIMING_ADD(r, cfg, OM_CACHE_READ); + /* see if it is any good */ if ((cache_value == NULL) && (encrypted == 1) && (cfg->crypto_passphrase.secret2 != NULL)) { oidc_debug(r, "2nd try with previous passphrase"); @@ -311,14 +317,15 @@ apr_byte_t oidc_cache_get(request_rec *r, const char *section, const char *key, /* log the result */ msg = apr_psprintf(r->pool, "from %s cache backend for %skey %s", cfg->cache->name, encrypted ? "encrypted " : "", key); - if (rc == TRUE) + if (rc == TRUE) { if (*value != NULL) oidc_debug(r, "cache hit: return %d bytes %s", *value ? (int)_oidc_strlen(*value) : 0, msg); else oidc_debug(r, "cache miss %s", msg); - else + } else { + OIDC_METRICS_COUNTER_INC(r, cfg, OM_CACHE_ERROR); oidc_warn(r, "error retrieving value %s", msg); - + } return rc; } @@ -356,18 +363,23 @@ apr_byte_t oidc_cache_set(request_rec *r, const char *section, const char *key, } } + OIDC_METRICS_TIMING_START(r, cfg); + /* store the resulting value in the cache */ rc = cfg->cache->set(r, section, key, value, expiry); + OIDC_METRICS_TIMING_ADD(r, cfg, OM_CACHE_WRITE); + out: /* log the result */ msg = apr_psprintf(r->pool, "%d bytes in %s cache backend for %skey %s", (value ? (int)_oidc_strlen(value) : 0), (cfg->cache->name ? cfg->cache->name : ""), (encrypted ? "encrypted " : ""), (key ? key : "")); - if (rc == TRUE) + if (rc == TRUE) { oidc_debug(r, "successfully stored %s", msg); - else + } else { + OIDC_METRICS_COUNTER_INC(r, cfg, OM_CACHE_ERROR); oidc_warn(r, "could NOT store %s", msg); - + } return rc; } diff --git a/src/metadata.c b/src/metadata.c index 0832237f..2149a22d 100644 --- a/src/metadata.c +++ b/src/metadata.c @@ -45,6 +45,8 @@ #include "mod_auth_openidc.h" +#include "metrics.h" + extern module AP_MODULE_DECLARE_DATA auth_openidc_module; #define OIDC_METADATA_SUFFIX_PROVIDER "provider" @@ -663,11 +665,17 @@ apr_byte_t oidc_metadata_jwks_get(request_rec *r, oidc_cfg *cfg, const oidc_jwks apr_byte_t oidc_metadata_provider_retrieve(request_rec *r, oidc_cfg *cfg, const char *issuer, const char *url, json_t **j_metadata, char **response) { + OIDC_METRICS_TIMING_START(r, cfg); + /* get provider metadata from the specified URL with the specified parameters */ if (oidc_util_http_get(r, url, NULL, NULL, NULL, cfg->provider.ssl_validate_server, response, &cfg->http_timeout_short, &cfg->outgoing_proxy, oidc_dir_cfg_pass_cookies(r), NULL, NULL, - NULL) == FALSE) + NULL) == FALSE) { + OIDC_METRICS_COUNTER_INC(r, cfg, OM_PROVIDER_METADATA_ERROR); return FALSE; + } + + OIDC_METRICS_TIMING_ADD(r, cfg, OM_PROVIDER_METADATA); /* decode and see if it is not an error response somehow */ if (oidc_util_decode_json_and_check_error(r, *response, j_metadata) == FALSE) { diff --git a/src/metrics.c b/src/metrics.c index 5288b7e8..e0fd431f 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -48,17 +48,36 @@ #define OM_CLASS_AUTH_TYPE "authtype" #define OM_CLASS_AUTHN "authn" +#define OM_CLASS_AUTHZ "authz" +#define OM_CLASS_REQUESTS "requests" #define OM_CLASS_SESSION "session" +#define OM_CLASS_CACHE "cache" #define OM_CLASS_CONTENT "content" #define OM_CLASS_REDIRECT_URI "redirect_uri" const oidc_metrics_timing_info_t _oidc_metrics_timings_info[] = { + { OM_AUTHN_REQUEST, OM_CLASS_AUTHN, "request", "authentication requests" }, { OM_AUTHN_RESPONSE, OM_CLASS_AUTHN, "response", "authentication responses" }, { OM_SESSION_VALID, OM_CLASS_SESSION, "valid", "successfully validated existing sessions" }, + + { OM_PROVIDER_METADATA, OM_CLASS_REQUESTS, "metadata", + "provider discovery document requests" }, + { OM_PROVIDER_TOKEN, OM_CLASS_REQUESTS, "token", + "provider token requests" }, + { OM_PROVIDER_REFRESH, OM_CLASS_REQUESTS, "refresh", + "provider refresh token requests" }, + { OM_PROVIDER_USERINFO, OM_CLASS_REQUESTS, "userinfo", + "provider userinfo requests" }, + + { OM_CACHE_READ, OM_CLASS_CACHE, "read", + "cache read requests" }, + { OM_CACHE_WRITE, OM_CLASS_CACHE, "write", + "cache write requests" }, + }; const oidc_metrics_counter_info_t _oidc_metrics_counters_info[] = { @@ -72,19 +91,8 @@ const oidc_metrics_counter_info_t _oidc_metrics_counters_info[] = { { OM_AUTHTYPE_DECLINED, OM_CLASS_AUTH_TYPE, "handler", "declined", "incoming requests" }, - { OM_SESSION_ERROR_COOKIE_DOMAIN, OM_CLASS_SESSION, "error", "cookie-domain", - "cookie domain validation errors for existing sessions" }, - { OM_SESSION_ERROR_EXPIRED, OM_CLASS_SESSION, "error", "expired", - "sessions that exceeded the maximum duration" }, - { OM_SESSION_ERROR_REFRESH_ACCESS_TOKEN, OM_CLASS_SESSION, "error", "refresh-access-token", - "errors refreshing the access token before expiry in existing sessions" }, - { OM_SESSION_ERROR_REFRESH_USERINFO, OM_CLASS_SESSION, "error", "refresh-user-info", - "errors refreshing claims from the userinfo endpoint in existing sessions" }, - { OM_SESSION_ERROR_GENERAL, OM_CLASS_SESSION, "error", "general", - "existing sessions that failed validation" }, - - { OM_AUTHN_REQUEST_ERROR_URL, OM_CLASS_AUTHN, "request.error", "url", - "errors matching the incoming request URL against the configuration" }, + { OM_AUTHN_REQUEST_ERROR_URL, OM_CLASS_AUTHN, "request.error", "url", + "errors matching the incoming request URL against the configuration" }, { OM_AUTHN_RESPONSE_ERROR_STATE_MISMATCH, OM_CLASS_AUTHN, "response.error", "state-mismatch", "state mismatch errors in authentication responses" }, @@ -97,6 +105,42 @@ const oidc_metrics_counter_info_t _oidc_metrics_counters_info[] = { { OM_AUTHN_RESPONSE_ERROR_REMOTE_USER, OM_CLASS_AUTHN, "response.error", "remote-user", "errors identifying the remote user based on provided claims" }, + { OM_AUTHZ_ERROR_GENERAL, OM_CLASS_AUTHZ, "error", "general", + "authorization errors" }, + { OM_AUTHZ_ACTION_AUTH, OM_CLASS_AUTHZ, "action", "auth", + "step-up authentication requests" }, + { OM_AUTHZ_ACTION_401, OM_CLASS_AUTHZ, "action", "401", + "401 authorization errors" }, + { OM_AUTHZ_ACTION_403, OM_CLASS_AUTHZ, "action", "403", + "403 authorization errors" }, + { OM_AUTHZ_ACTION_302, OM_CLASS_AUTHZ, "action", "302", + "302 authorization errors" }, + { OM_AUTHZ_ERROR_OAUTH20, OM_CLASS_AUTHZ, "error", "oauth20", + "AuthType oauth20 authorization errors 401" }, + + { OM_PROVIDER_METADATA_ERROR, OM_CLASS_REQUESTS, "provider.metadata", "error" + "errors retrieving provider discovery document" }, + { OM_PROVIDER_TOKEN_ERROR, OM_CLASS_REQUESTS, "provider.token", "error", + "errors making a token request to the provider" }, + { OM_PROVIDER_REFRESH_ERROR, OM_CLASS_REQUESTS, "provider.refresh", "error", + "errors refreshing the access token" }, + { OM_PROVIDER_USERINFO_ERROR, OM_CLASS_REQUESTS, "provider.userinfo", "error", + "errors calling the provider userinfo endpoint" }, + + { OM_SESSION_ERROR_COOKIE_DOMAIN, OM_CLASS_SESSION, "error", "cookie-domain", + "cookie domain validation errors for existing sessions" }, + { OM_SESSION_ERROR_EXPIRED, OM_CLASS_SESSION, "error", "expired", + "sessions that exceeded the maximum duration" }, + { OM_SESSION_ERROR_REFRESH_ACCESS_TOKEN, OM_CLASS_SESSION, "error", "refresh-access-token", + "errors refreshing the access token before expiry in existing sessions" }, + { OM_SESSION_ERROR_REFRESH_USERINFO, OM_CLASS_SESSION, "error", "refresh-user-info", + "errors refreshing claims from the userinfo endpoint in existing sessions" }, + { OM_SESSION_ERROR_GENERAL, OM_CLASS_SESSION, "error", "general", + "existing sessions that failed validation" }, + + { OM_CACHE_ERROR, OM_CLASS_CACHE, "cache", "error", + "cache read/write errors" }, + { OM_REDIRECT_URI_AUTHN_RESPONSE_REDIRECT, OM_CLASS_REDIRECT_URI, "authn.response", "redirect", "authentication responses received in a redirect", }, { OM_REDIRECT_URI_AUTHN_RESPONSE_POST, OM_CLASS_REDIRECT_URI, "authn.response", "post", @@ -138,6 +182,7 @@ const oidc_metrics_counter_info_t _oidc_metrics_counters_info[] = { "HTTP POST preservation requests to the content handler" }, { OM_CONTENT_REQUEST_UNKNOWN, OM_CLASS_CONTENT, "request", "unknown", "unknown requests to the content handler" }, + }; // clang-format on diff --git a/src/metrics.h b/src/metrics.h index 0e9a89dc..51a294fc 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -49,7 +49,17 @@ apr_status_t oidc_metrics_cache_child_init(apr_pool_t *p, server_rec *s); apr_status_t oidc_metrics_cache_cleanup(server_rec *s); int oidc_metrics_handle_request(request_rec *r); -typedef enum { OM_AUTHN_REQUEST = 0, OM_AUTHN_RESPONSE, OM_SESSION_VALID } oidc_metrics_timing_type_t; +typedef enum { + OM_AUTHN_REQUEST = 0, + OM_AUTHN_RESPONSE, + OM_SESSION_VALID, + OM_PROVIDER_METADATA, + OM_PROVIDER_TOKEN, + OM_PROVIDER_REFRESH, + OM_PROVIDER_USERINFO, + OM_CACHE_READ, + OM_CACHE_WRITE, +} oidc_metrics_timing_type_t; typedef struct oidc_metrics_timing_info_t { oidc_metrics_timing_type_t type; @@ -80,12 +90,6 @@ typedef enum { OM_AUTHTYPE_AUTH_OPENIDC, OM_AUTHTYPE_DECLINED, - OM_SESSION_ERROR_COOKIE_DOMAIN, - OM_SESSION_ERROR_EXPIRED, - OM_SESSION_ERROR_REFRESH_ACCESS_TOKEN, - OM_SESSION_ERROR_REFRESH_USERINFO, - OM_SESSION_ERROR_GENERAL, - OM_AUTHN_REQUEST_ERROR_URL, OM_AUTHN_RESPONSE_ERROR_STATE_MISMATCH, @@ -94,6 +98,26 @@ typedef enum { OM_AUTHN_RESPONSE_ERROR_PROTOCOL, OM_AUTHN_RESPONSE_ERROR_REMOTE_USER, + OM_AUTHZ_ERROR_GENERAL, + OM_AUTHZ_ACTION_AUTH, + OM_AUTHZ_ACTION_401, + OM_AUTHZ_ACTION_403, + OM_AUTHZ_ACTION_302, + OM_AUTHZ_ERROR_OAUTH20, + + OM_PROVIDER_METADATA_ERROR, + OM_PROVIDER_TOKEN_ERROR, + OM_PROVIDER_REFRESH_ERROR, + OM_PROVIDER_USERINFO_ERROR, + + OM_SESSION_ERROR_COOKIE_DOMAIN, + OM_SESSION_ERROR_EXPIRED, + OM_SESSION_ERROR_REFRESH_ACCESS_TOKEN, + OM_SESSION_ERROR_REFRESH_USERINFO, + OM_SESSION_ERROR_GENERAL, + + OM_CACHE_ERROR, + OM_REDIRECT_URI_AUTHN_RESPONSE_REDIRECT, OM_REDIRECT_URI_AUTHN_RESPONSE_POST, OM_REDIRECT_URI_AUTHN_RESPONSE_IMPLICIT, diff --git a/src/mod_auth_openidc.c b/src/mod_auth_openidc.c index 3a65db9d..5804dee9 100644 --- a/src/mod_auth_openidc.c +++ b/src/mod_auth_openidc.c @@ -1064,15 +1064,20 @@ static apr_byte_t oidc_refresh_token_grant(request_rec *r, oidc_cfg *c, oidc_ses oidc_debug(r, "refreshing refresh_token: %s", refresh_token); // don't unlock after this since other processes may be waiting for the lock to refresh the same refresh token + OIDC_METRICS_TIMING_START(r, c); + /* refresh the tokens by calling the token endpoint */ if (oidc_proto_refresh_request(r, c, provider, refresh_token, &s_id_token, &s_access_token, &s_token_type, &expires_in, &s_refresh_token) == FALSE) { + OIDC_METRICS_COUNTER_INC(r, c, OM_PROVIDER_REFRESH_ERROR); oidc_error(r, "access_token could not be refreshed with refresh_token: %s", refresh_token); if (*error_code != OIDC_REFRESH_ERROR_PARALLEL_REFRESH) *error_code = OIDC_REFRESH_ERROR_GENERAL; goto end; } + OIDC_METRICS_TIMING_ADD(r, c, OM_PROVIDER_REFRESH); + /* store the new access_token in the session and discard the old one */ oidc_session_set_access_token(r, session, s_access_token); oidc_session_set_access_token_expires(r, session, expires_in); @@ -4327,6 +4332,7 @@ static authz_status oidc_handle_unauthorized_user24(request_rec *r) { oidc_cfg *c = ap_get_module_config(r->server->module_config, &auth_openidc_module); if (apr_strnatcasecmp((const char *)ap_auth_type(r), OIDC_AUTH_TYPE_OPENID_OAUTH20) == 0) { + OIDC_METRICS_COUNTER_INC(r, c, OM_AUTHZ_ERROR_OAUTH20); oidc_debug(r, "setting environment variable %s to \"%s\" for usage in mod_headers", OIDC_OAUTH_BEARER_SCOPE_ERROR, OIDC_OAUTH_BEARER_SCOPE_ERROR_VALUE); apr_table_set(r->subprocess_env, OIDC_OAUTH_BEARER_SCOPE_ERROR, OIDC_OAUTH_BEARER_SCOPE_ERROR_VALUE); @@ -4337,12 +4343,14 @@ static authz_status oidc_handle_unauthorized_user24(request_rec *r) { switch (oidc_dir_cfg_unautz_action(r)) { case OIDC_UNAUTZ_RETURN403: case OIDC_UNAUTZ_RETURN401: + OIDC_METRICS_COUNTER_INC(r, c, OM_AUTHZ_ACTION_401); oidc_util_html_send_error(r, c->error_template, "Authorization Error", oidc_dir_cfg_unauthz_arg(r), HTTP_UNAUTHORIZED); if (c->error_template) r->header_only = 1; return AUTHZ_DENIED; case OIDC_UNAUTZ_RETURN302: + OIDC_METRICS_COUNTER_INC(r, c, OM_AUTHZ_ACTION_302); html_head = apr_psprintf(r->pool, "", oidc_dir_cfg_unauthz_arg(r)); oidc_util_html_send(r, "Authorization Error Redirect", html_head, NULL, NULL, HTTP_UNAUTHORIZED); @@ -4354,8 +4362,13 @@ static authz_status oidc_handle_unauthorized_user24(request_rec *r) { * complete an authentication round trip to the provider, we * won't redirect the user and thus avoid creating a state cookie */ - if (oidc_is_auth_capable_request(r) == FALSE) + if (oidc_is_auth_capable_request(r) == FALSE) { + OIDC_METRICS_COUNTER_INC(r, c, OM_AUTHZ_ACTION_401); return AUTHZ_DENIED; + } + + OIDC_METRICS_COUNTER_INC(r, c, OM_AUTHZ_ACTION_AUTH); + break; } @@ -4440,6 +4453,7 @@ static int oidc_handle_unauthorized_user22(request_rec *r) { oidc_cfg *c = ap_get_module_config(r->server->module_config, &auth_openidc_module); if (apr_strnatcasecmp((const char *)ap_auth_type(r), OIDC_AUTH_TYPE_OPENID_OAUTH20) == 0) { + OIDC_COUNTER_INC(r, cfg, OM_AUTHZ_ERROR_OAUTH20); oidc_oauth_return_www_authenticate(r, "insufficient_scope", "Different scope(s) or other claims required"); return HTTP_UNAUTHORIZED; @@ -4448,16 +4462,19 @@ static int oidc_handle_unauthorized_user22(request_rec *r) { /* see if we've configured OIDCUnAutzAction for this path */ switch (oidc_dir_cfg_unautz_action(r)) { case OIDC_UNAUTZ_RETURN403: + OIDC_COUNTER_INC(r, cfg, OM_AUTHZ_ACTION_403); if (oidc_dir_cfg_unauthz_arg(r)) oidc_util_html_send(r, "Authorization Error", NULL, NULL, oidc_dir_cfg_unauthz_arg(r), HTTP_FORBIDDEN); return HTTP_FORBIDDEN; case OIDC_UNAUTZ_RETURN401: + OIDC_COUNTER_INC(r, cfg, OM_AUTHZ_ACTION_401); if (oidc_dir_cfg_unauthz_arg(r)) oidc_util_html_send(r, "Authorization Error", NULL, NULL, oidc_dir_cfg_unauthz_arg(r), HTTP_UNAUTHORIZED); return HTTP_UNAUTHORIZED; case OIDC_UNAUTZ_RETURN302: + OIDC_COUNTER_INC(r, cfg, OM_AUTHZ_ACTION_302); oidc_util_hdr_out_location_set(r, oidc_dir_cfg_unauthz_arg(r)); return HTTP_MOVED_TEMPORARILY; case OIDC_UNAUTZ_AUTHENTICATE: @@ -4466,8 +4483,12 @@ static int oidc_handle_unauthorized_user22(request_rec *r) { * won't redirect the user and thus avoid creating a state cookie * for a non-browser (= Javascript) call that will never return from the OP */ - if (oidc_is_auth_capable_request(r) == FALSE) + if (oidc_is_auth_capable_request(r) == FALSE) { + OIDC_COUNTER_INC(r, c, OM_AUTHZ_ACTION_401); return HTTP_UNAUTHORIZED; + } + + OIDC_COUNTER_INC(r, cfg, OM_AUTHZ_ACTION_AUTH); } return oidc_authenticate_user(r, c, NULL, oidc_get_current_url(r, c->x_forwarded_headers), NULL, NULL, NULL, diff --git a/src/proto.c b/src/proto.c index 56eae116..360c15d6 100644 --- a/src/proto.c +++ b/src/proto.c @@ -43,6 +43,8 @@ #include "mod_auth_openidc.h" +#include "metrics.h" + #include #include @@ -2069,25 +2071,33 @@ apr_byte_t oidc_proto_resolve_userinfo(request_rec *r, oidc_cfg *cfg, oidc_provi oidc_debug(r, "enter, endpoint=%s, access_token=%s", provider->userinfo_endpoint_url, access_token); + OIDC_METRICS_TIMING_START(r, cfg); + /* get the JSON response */ if (provider->userinfo_token_method == OIDC_USER_INFO_TOKEN_METHOD_HEADER) { if (oidc_util_http_get(r, provider->userinfo_endpoint_url, NULL, NULL, access_token, provider->ssl_validate_server, response, &cfg->http_timeout_long, - &cfg->outgoing_proxy, oidc_dir_cfg_pass_cookies(r), NULL, NULL, NULL) == FALSE) + &cfg->outgoing_proxy, oidc_dir_cfg_pass_cookies(r), NULL, NULL, NULL) == FALSE) { + OIDC_METRICS_COUNTER_INC(r, cfg, OM_PROVIDER_USERINFO_ERROR); return FALSE; + } } else if (provider->userinfo_token_method == OIDC_USER_INFO_TOKEN_METHOD_POST) { apr_table_t *params = apr_table_make(r->pool, 4); apr_table_setn(params, OIDC_PROTO_ACCESS_TOKEN, access_token); if (oidc_util_http_post_form(r, provider->userinfo_endpoint_url, params, NULL, NULL, provider->ssl_validate_server, response, &cfg->http_timeout_long, &cfg->outgoing_proxy, oidc_dir_cfg_pass_cookies(r), NULL, NULL, - NULL) == FALSE) + NULL) == FALSE) { + OIDC_METRICS_COUNTER_INC(r, cfg, OM_PROVIDER_USERINFO_ERROR); return FALSE; + } } else { oidc_error(r, "unsupported userinfo token presentation method: %d", provider->userinfo_token_method); return FALSE; } + OIDC_METRICS_TIMING_ADD(r, cfg, OM_PROVIDER_USERINFO); + json_t *claims = NULL; if (oidc_user_info_response_validate(r, cfg, provider, response, &claims, userinfo_jwt) == FALSE) return FALSE; @@ -2643,12 +2653,17 @@ static apr_byte_t oidc_proto_resolve_code_and_validate_response(request_rec *r, const char *state = oidc_proto_state_get_state(proto_state); + OIDC_METRICS_TIMING_START(r, c); + if (oidc_proto_resolve_code(r, c, provider, apr_table_get(params, OIDC_PROTO_CODE), code_verifier, &id_token, &access_token, &token_type, &expires_in, &refresh_token, state) == FALSE) { oidc_error(r, "failed to resolve the code"); + OIDC_METRICS_COUNTER_INC(r, c, OM_PROVIDER_TOKEN_ERROR); return FALSE; } + OIDC_METRICS_TIMING_ADD(r, c, OM_PROVIDER_TOKEN); + if (oidc_proto_validate_code_response(r, response_type, id_token, access_token, token_type) == FALSE) { oidc_error(r, "code response validation failed"); return FALSE;