move the timing metrics into the token/userinfo code

so we also measure the 2nd request the use_dpop_nonce cases

Signed-off-by: Hans Zandbelt <[email protected]>

src/proto/response.c

@@ -333,17 +333,13 @@ 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;

src/proto/token.c

@@ -40,6 +40,7 @@
  * @Author: Hans Zandbelt - [email protected]
  */
 
+#include "metrics.h"
 #include "proto/proto.h"
 #include "util.h"
 
@@ -68,6 +69,9 @@ static apr_byte_t oidc_proto_validate_token_type(request_rec *r, oidc_provider_t
 static apr_byte_t oidc_proto_token_endpoint_call(request_rec *r, oidc_cfg_t *cfg, oidc_provider_t *provider,
 						 apr_table_t *params, const char *basic_auth, const char *bearer_auth,
 						 const char *dpop, char **response, apr_hash_t *response_hdrs) {
+
+	OIDC_METRICS_TIMING_START(r, cfg);
+
 	// oidc_debug(r, "cert=%s, key=%s, pwd=%s", oidc_cfg_provider_token_endpoint_tls_client_cert_get(provider),
 	// oidc_cfg_provider_token_endpoint_tls_client_key_get(provider),
 	// oidc_cfg_provider_token_endpoint_tls_client_key_pwd_get(provider));
@@ -82,6 +86,9 @@ static apr_byte_t oidc_proto_token_endpoint_call(request_rec *r, oidc_cfg_t *cfg
 			   oidc_cfg_provider_token_endpoint_url_get(provider));
 		return FALSE;
 	}
+
+	OIDC_METRICS_TIMING_ADD(r, cfg, OM_PROVIDER_TOKEN);
+
 	return TRUE;
 }
 

src/proto/userinfo.c

@@ -242,6 +242,9 @@ static apr_byte_t oidc_proto_userinfo_request_composite_claims(request_rec *r, o
 static apr_byte_t oidc_proto_userinfo_endpoint_call(request_rec *r, oidc_cfg_t *cfg, oidc_provider_t *provider,
 						    const char *access_token, const char *dpop, char **response,
 						    long *response_code, apr_hash_t *response_hdrs) {
+
+	OIDC_METRICS_TIMING_START(r, cfg);
+
 	/* get the JSON response */
 	if (oidc_cfg_provider_userinfo_token_method_get(provider) == OIDC_USER_INFO_TOKEN_METHOD_HEADER) {
 		if (oidc_http_get(r, oidc_cfg_provider_userinfo_endpoint_url_get(provider), NULL, NULL, access_token,
@@ -267,6 +270,9 @@ static apr_byte_t oidc_proto_userinfo_endpoint_call(request_rec *r, oidc_cfg_t *
 			   oidc_cfg_provider_userinfo_token_method_get(provider));
 		return FALSE;
 	}
+
+	OIDC_METRICS_TIMING_ADD(r, cfg, OM_PROVIDER_USERINFO);
+
 	return TRUE;
 }
 
@@ -287,8 +293,6 @@ apr_byte_t oidc_proto_userinfo_request(request_rec *r, oidc_cfg_t *cfg, oidc_pro
 	oidc_debug(r, "enter, endpoint=%s, access_token=%s, token_type=%s",
 		   oidc_cfg_provider_userinfo_endpoint_url_get(provider), access_token, access_token_type);
 
-	OIDC_METRICS_TIMING_START(r, cfg);
-
 	if (_oidc_strnatcasecmp(access_token_type, OIDC_PROTO_DPOP) == 0) {
 		response_hdrs = apr_hash_make(r->pool);
 		apr_hash_set(response_hdrs, OIDC_HTTP_HDR_AUTHORIZATION, APR_HASH_KEY_STRING, "");
@@ -303,8 +307,6 @@ apr_byte_t oidc_proto_userinfo_request(request_rec *r, oidc_cfg_t *cfg, oidc_pro
 					      response_hdrs) == FALSE)
 		goto end;
 
-	OIDC_METRICS_TIMING_ADD(r, cfg, OM_PROVIDER_USERINFO);
-
 	if (oidc_util_decode_json_object_err(r, *response, &j_result, FALSE) == FALSE) {
 
 		// must be a JWT