From ad677c6d3900a94ea8d7e6b99d2afe4832b627ce Mon Sep 17 00:00:00 2001 From: Hans Zandbelt Date: Thu, 14 Dec 2023 20:30:17 +0100 Subject: [PATCH] add metrics/observability capability OIDCMetricsData/OIDCMetricsPublish bump to 2.4.15rc8 Signed-off-by: Hans Zandbelt --- ChangeLog | 4 + Makefile.am | 2 + auth_openidc.conf | 17 + configure.ac | 2 +- src/config.c | 43 +++ src/metrics.c | 701 +++++++++++++++++++++++++++++++++++++++++ src/metrics.h | 72 +++++ src/mod_auth_openidc.c | 216 +++++++++++-- src/mod_auth_openidc.h | 4 + 9 files changed, 1027 insertions(+), 34 deletions(-) create mode 100644 src/metrics.c create mode 100644 src/metrics.h diff --git a/ChangeLog b/ChangeLog index f687e3e1..44425795 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,7 @@ +12/14/2023 +- add metrics collection capability, configured with OIDCMetricsData and retrieved through OIDCMetricsPublish +- bump to 2.4.15rc8 + 11/30/2023 - fix SSL server certificate validation when revoking tokens apply `OIDCSSLValidateServer` setting rather than `OIDCOAuthSSLValidateServer` in `oidc_revoke_tokens` diff --git a/Makefile.am b/Makefile.am index ea7c1c4c..94ae788e 100644 --- a/Makefile.am +++ b/Makefile.am @@ -7,6 +7,7 @@ libauth_openidc_la_SOURCES = \ src/cache/file.c \ src/cache/shm.c \ src/cache/common.c \ + src/metrics.c \ src/oauth.c \ src/proto.c \ src/config.c \ @@ -56,6 +57,7 @@ noinst_HEADERS = \ src/const.h \ src/jose.h \ src/parse.h \ + src/metrics.h \ src/cache/cache.h \ src/pcre_subst.h diff --git a/auth_openidc.conf b/auth_openidc.conf index a5e5d42e..cc873014 100644 --- a/auth_openidc.conf +++ b/auth_openidc.conf @@ -1011,6 +1011,23 @@ # When not defined the session hook will not return any data but a HTTP 404 #OIDCInfoHook [iat|access_token|access_token_expires|id_token|id_token_hint|userinfo|refresh_token|exp|timeout|remote_user|session]+ +# 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 +# session: existing session handling +# 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 ]+ + +# Specify the path where metrics are published and can be consumed. +# The "format=" parameter can be passed to specify the format of the data. +# The default is "prometheus", "json" is also supported. +# Protect protect this path (e.g. Require host localhost) or serve it on an internal co-located vhost/port. +# When not defined, no metrics will be published on the enclosing vhost. +#OIDCMetricsPublish + # Specify claims that should be removed from the userinfo and/or id_token before storing them in the session. # Note that OIDCBlackListedClaims takes precedence over OIDCWhiteListedClaims # When not defined no claims are blacklisted and all claims are stored except when OIDCWhiteListedClaims is used. diff --git a/configure.ac b/configure.ac index 04ead2ea..4dc09aa9 100644 --- a/configure.ac +++ b/configure.ac @@ -1,4 +1,4 @@ -AC_INIT([mod_auth_openidc],[2.4.15rc7],[hans.zandbelt@openidc.com]) +AC_INIT([mod_auth_openidc],[2.4.15rc8],[hans.zandbelt@openidc.com]) AC_SUBST(NAMEVER, AC_PACKAGE_TARNAME()-AC_PACKAGE_VERSION()) diff --git a/src/config.c b/src/config.c index c3abb740..dcd731b9 100644 --- a/src/config.c +++ b/src/config.c @@ -41,7 +41,12 @@ * @Author: Hans Zandbelt - hans.zandbelt@openidc.com */ +// clang-format off + #include "mod_auth_openidc.h" +#include "metrics.h" + +// clang-format on #include @@ -1124,6 +1129,14 @@ static const char *oidc_set_info_hook_data(cmd_parms *cmd, void *m, const char * return OIDC_CONFIG_DIR_RV(cmd, rv); } +static const char *oidc_set_metrics_hook_data(cmd_parms *cmd, void *m, const char *arg) { + oidc_cfg *cfg = (oidc_cfg *)ap_get_module_config(cmd->server->module_config, &auth_openidc_module); + if (cfg->metrics_hook_data == NULL) + cfg->metrics_hook_data = apr_hash_make(cmd->pool); + apr_hash_set(cfg->metrics_hook_data, arg, APR_HASH_KEY_STRING, arg); + return NULL; +} + static const char *oidc_set_filtered_claims(cmd_parms *cmd, void *m, const char *arg) { oidc_cfg *cfg = (oidc_cfg *)ap_get_module_config(cmd->server->module_config, &auth_openidc_module); int offset = (int)(long)cmd->info; @@ -1642,6 +1655,9 @@ void *oidc_create_server_config(apr_pool_t *pool, server_rec *svr) { c->provider_metadata_refresh_interval = OIDC_DEFAULT_PROVIDER_METADATA_REFRESH_INTERVAL; c->info_hook_data = NULL; + c->metrics_hook_data = NULL; + c->metrics_path = NULL; + c->black_listed_claims = NULL; c->white_listed_claims = NULL; c->filter_claims_expr = NULL; @@ -1888,6 +1904,9 @@ void *oidc_merge_server_config(apr_pool_t *pool, void *BASE, void *ADD) { : base->provider_metadata_refresh_interval; c->info_hook_data = add->info_hook_data != NULL ? add->info_hook_data : base->info_hook_data; + c->metrics_hook_data = add->metrics_hook_data != NULL ? add->metrics_hook_data : base->metrics_hook_data; + c->metrics_path = add->metrics_path != NULL ? add->metrics_path : base->metrics_path; + c->black_listed_claims = add->black_listed_claims != NULL ? add->black_listed_claims : base->black_listed_claims; c->white_listed_claims = @@ -2439,6 +2458,11 @@ static apr_status_t oidc_cleanup_child(void *data) { oidc_serror(sp, "oidc_cache_mutex_destroy on refresh mutex failed"); } } + if (cfg->metrics_hook_data != NULL) { + if (oidc_metrics_cache_cleanup(sp) != APR_SUCCESS) { + oidc_serror(sp, "oidc_metrics_cache_cleanup failed"); + } + } sp = sp->next; } @@ -2548,6 +2572,10 @@ static int oidc_post_config(apr_pool_t *pool, apr_pool_t *p1, apr_pool_t *p2, se if (oidc_cache_mutex_post_config(sp, cfg->refresh_mutex, "refresh") != TRUE) return HTTP_INTERNAL_SERVER_ERROR; } + if (cfg->metrics_hook_data != NULL) { + if (oidc_metrics_cache_post_config(s) != TRUE) + return HTTP_INTERNAL_SERVER_ERROR; + } sp = sp->next; } @@ -2617,6 +2645,11 @@ static void oidc_child_init(apr_pool_t *p, server_rec *s) { oidc_serror(sp, "oidc_cache_mutex_child_init on refresh mutex failed"); } } + if (cfg->metrics_hook_data != NULL) { + if (oidc_metrics_cache_child_init(p, s) != APR_SUCCESS) { + oidc_serror(sp, "oidc_metrics_cache_child_init failed"); + } + } sp = sp->next; } apr_pool_cleanup_register(p, s, oidc_cleanup_child, apr_pool_cleanup_null); @@ -3365,6 +3398,16 @@ const command_rec oidc_config_cmds[] = { (void *)APR_OFFSETOF(oidc_cfg, info_hook_data), RSRC_CONF, "The data that will be returned from the info hook."), + AP_INIT_ITERATE(OIDCMetricsData, + oidc_set_metrics_hook_data, + (void *)APR_OFFSETOF(oidc_cfg, metrics_hook_data), + RSRC_CONF, + "The data that will be returned from the metrics hook."), + AP_INIT_TAKE1(OIDCMetricsPublish, + oidc_set_string_slot, + (void *)APR_OFFSETOF(oidc_cfg, metrics_path), + RSRC_CONF, + "Define the URL where the metrics will be published (e.g.: /metrics)"), AP_INIT_ITERATE(OIDCBlackListedClaims, oidc_set_filtered_claims, (void *) APR_OFFSETOF(oidc_cfg, black_listed_claims), diff --git a/src/metrics.c b/src/metrics.c new file mode 100644 index 00000000..a9f74fac --- /dev/null +++ b/src/metrics.c @@ -0,0 +1,701 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +/*************************************************************************** + * Copyright (C) 2023 ZmartZone Holding BV + * All rights reserved. + * + * DISCLAIMER OF WARRANTIES: + * + * THE SOFTWARE PROVIDED HEREUNDER IS PROVIDED ON AN "AS IS" BASIS, WITHOUT + * ANY WARRANTIES OR REPRESENTATIONS EXPRESS, IMPLIED OR STATUTORY; INCLUDING, + * WITHOUT LIMITATION, WARRANTIES OF QUALITY, PERFORMANCE, NONINFRINGEMENT, + * MERCHANTABILITY OR FITNESS FOR A PARTICULAR PURPOSE. NOR ARE THERE ANY + * WARRANTIES CREATED BY A COURSE OR DEALING, COURSE OF PERFORMANCE OR TRADE + * USAGE. FURTHERMORE, THERE ARE NO WARRANTIES THAT THE SOFTWARE WILL MEET + * YOUR NEEDS OR BE FREE FROM ERRORS, OR THAT THE OPERATION OF THE SOFTWARE + * WILL BE UNINTERRUPTED. IN NO EVENT SHALL THE COPYRIGHT HOLDERS OR + * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, + * EXEMPLARY, OR CONSEQUENTIAL DAMAGES HOWEVER CAUSED AND ON ANY THEORY OF + * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING + * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS + * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + * @Author: Hans Zandbelt - hans.zandbelt@openidc.com + */ + +// clang-format off + +#include "mod_auth_openidc.h" +#include "metrics.h" +#include + +// clang-format on + +typedef struct oidc_metrics_t { + apr_hash_t *counters; + apr_hash_t *timings; +} oidc_metrics_t; + +// pointer to the shared memory segment that holds the JSON metrics data +static apr_shm_t *_oidc_metrics_cache = NULL; +// flag to record if we are a parent process or a child process +static apr_byte_t _oidc_metrics_is_parent = FALSE; +// flag to signal the metrics write thread to exit +static apr_byte_t _oidc_metrics_thread_exit = FALSE; +// mutex to protect the shared memory storage +static oidc_cache_mutex_t *_oidc_metrics_global_mutex = NULL; +// pointer to the thread that periodically writes the locally gathered metrics to shared memory +static apr_thread_t *_oidc_metrics_thread = NULL; +// local in-memory cached metrics +static oidc_metrics_t _oidc_metrics = {NULL, NULL}; +// mutex to protect the local metrics hash table +static oidc_cache_mutex_t *_oidc_metrics_process_mutex = NULL; + +// shared memory write interval in seconds +#define OIDC_CACHE_METRICS_STORAGE_INTERVAL 5 + +// maximum length of the string representation of the global JSON metrics data in shared memory +// 1024 sample size (non-compact, long keys, large json_int values), timing + counter +// 256 number of individual metrics collected +// 4 number of vhosts supported +#define OIDC_CACHE_METRICS_JSON_MAX 1024 * 256 * 4 + +typedef struct oidc_metrics_bucket_t { + const char *name; + const char *label; + apr_time_t threshold; +} oidc_metrics_bucket_t; + +// clang-format off + +static oidc_metrics_bucket_t _oidc_metric_buckets[] = { + //{ "le005", "bucket{le=\"0.05\"}", 50 }, + { "le01", "bucket{le=\"0.1\"}", 100 }, + { "le05", "bucket{le=\"0.5\"}", 500 }, + { "le1", "bucket{le=\"1\"}", apr_time_from_msec(1) }, + { "le5", "bucket{le=\"5\"}", apr_time_from_msec(5) }, + { "le10", "bucket{le=\"10\"}", apr_time_from_msec(10) }, + { "le50", "bucket{le=\"50\"}", apr_time_from_msec(50) }, + { "le100", "bucket{le=\"100\"}", apr_time_from_msec(100) }, + { "le500", "bucket{le=\"500\"}", apr_time_from_msec(500) }, + { "le1000", "bucket{le=\"1000\"}", apr_time_from_msec(1000) }, + { "le5000", "bucket{le=\"5000\"}", apr_time_from_msec(5000) }, + { "inf", "bucket{le=\"+Inf\"}", 0 } +}; + +#define OIDC_METRICS_BUCKET_NUM sizeof(_oidc_metric_buckets) / sizeof(oidc_metrics_bucket_t) + +// clang-format on + +// NB: shared between JSON and Prometheus formatting +#define OIDC_METRICS_SUM "sum" +#define OIDC_METRICS_COUNT "count" + +#define OIDC_METRICS_NAME "name" +#define OIDC_METRICS_LABEL_NAME "lname" +#define OIDC_METRICS_LABEL_VALUE "lvalue" +#define OIDC_METRICS_DESC "desc" + +#define OIDC_METRICS_TIMINGS "timings" +#define OIDC_METRICS_COUNTERS "counters" + +// single counter container +typedef struct oidc_metrics_counter_t { + const char *metric_name; + const char *label_name; + const char *label_value; + json_int_t count; + const char *desc; +} oidc_metrics_counter_t; + +// single timing stats container +typedef struct oidc_metrics_timing_t { + // json_int_t buckets[OIDC_METRICS_BUCKET_NUM]; + json_int_t *buckets; + apr_time_t sum; + json_int_t count; + const char *desc; +} oidc_metrics_timing_t; + +/* + * retrieve the (JSON) serialized (global) metrics data from shared memory + */ +static void oidc_metrics_storage_get(server_rec *s, char **value) { + char *p = apr_shm_baseaddr_get(_oidc_metrics_cache); + if (*p) + *value = apr_pstrdup(s->process->pool, p); +} + +/* + * store the serialized (global) metrics data in shared memory + */ +static void oidc_metrics_storage_set(server_rec *s, const char *value) { + char *p = apr_shm_baseaddr_get(_oidc_metrics_cache); + if (value) { + int n = strlen(value) + 1; + if (n > OIDC_CACHE_METRICS_JSON_MAX) + oidc_serror(s, "json value too large"); + else + _oidc_memcpy(p, value, n); + } else { + *p = 0; + } +} + +/* + * create a new counter entry in the collected JSON data + */ +static json_t *oidc_metrics_counter_new(server_rec *s, const oidc_metrics_counter_t *counter) { + int i = 0; + json_t *entry = json_object(); + json_object_set_new(entry, OIDC_METRICS_NAME, json_string(counter->metric_name)); + if (counter->label_name) { + json_object_set_new(entry, OIDC_METRICS_LABEL_NAME, json_string(counter->label_name)); + json_object_set_new(entry, OIDC_METRICS_LABEL_VALUE, json_string(counter->label_value)); + } + json_object_set_new(entry, OIDC_METRICS_COUNT, json_integer(counter->count)); + json_object_set_new(entry, OIDC_METRICS_DESC, json_string(counter->desc)); + return entry; +} + +/* + * create a new timings entry in the collected JSON data + */ +static json_t *oidc_metrics_timings_new(server_rec *s, const oidc_metrics_timing_t *timing) { + int i = 0; + json_t *entry = json_object(); + for (i = 0; i < OIDC_METRICS_BUCKET_NUM; i++) + json_object_set_new(entry, _oidc_metric_buckets[i].name, json_integer(timing->buckets[i])); + json_object_set_new(entry, OIDC_METRICS_SUM, json_integer(apr_time_as_msec(timing->sum))); + json_object_set_new(entry, OIDC_METRICS_COUNT, json_integer(timing->count)); + json_object_set_new(entry, OIDC_METRICS_DESC, json_string(timing->desc)); + return entry; +} + +/* + * update an entry in the collected JSON data + */ +static void oidc_metrics_timings_update(server_rec *s, const json_t *entry, const oidc_metrics_timing_t *timing) { + json_t *j_member = NULL; + json_int_t n = 0; + int i = 0; + + for (i = 0; i < OIDC_METRICS_BUCKET_NUM; i++) { + j_member = json_object_get(entry, _oidc_metric_buckets[i].name); + json_integer_set(j_member, json_integer_value(j_member) + timing->buckets[i]); + } + + j_member = json_object_get(entry, OIDC_METRICS_SUM); + n = json_integer_value(j_member); + // check Jansson specific integer/long overrun + if ((LONG_MAX - apr_time_as_msec(timing->sum)) < n) { + oidc_serror(s, + "cannot update metrics since the size (%ld" + ") of the integer value would be larger than the JSON/libjansson maximum " + "(%ld)", + (long int)n, LONG_MAX); + return; + } + json_integer_set(j_member, n + apr_time_as_msec(timing->sum)); + + j_member = json_object_get(entry, OIDC_METRICS_COUNT); + n = json_integer_value(j_member); + json_integer_set(j_member, n + timing->count); +} + +/* + * get or create the vhost entry in the global metrics + */ +static json_t *oidc_metrics_server_get(json_t *json, const char *name) { + json_t *j_server = json_object_get(json, name); + if (j_server == NULL) { + j_server = json_object(); + json_object_set_new(j_server, OIDC_METRICS_COUNTERS, json_object()); + json_object_set_new(j_server, OIDC_METRICS_TIMINGS, json_object()); + json_object_set_new(json, name, j_server); + } + return j_server; +} +/* + * flush the locally gathered metrics data into the global data kept in shared memory + */ +static void oidc_metrics_store(server_rec *s) { + char *s_json = NULL; + json_t *json = NULL, *j_server = NULL, *j_value = NULL, *j_counters = NULL, *j_timings = NULL, *j_member = NULL; + apr_hash_index_t *hi1 = NULL, *hi2 = NULL; + const char *name = NULL, *key = NULL; + apr_hash_t *server_hash = NULL; + oidc_metrics_timing_t *timing = NULL; + oidc_metrics_counter_t *counter = NULL; + json_error_t json_error; + + /* lock the shared memory for other processes */ + oidc_cache_mutex_lock(s->process->pool, s, _oidc_metrics_global_mutex); + + /* get the global stringified JSON metrics */ + oidc_metrics_storage_get(s, &s_json); + + /* parse the metrics string to JSON */ + if (s_json != NULL) + json = json_loads(s_json, 0, &json_error); + if (json == NULL) + json = json_object(); + + for (hi1 = apr_hash_first(s->process->pool, _oidc_metrics.counters); hi1; hi1 = apr_hash_next(hi1)) { + apr_hash_this(hi1, (const void **)&name, NULL, (void **)&server_hash); + + j_server = oidc_metrics_server_get(json, name); + j_counters = json_object_get(j_server, OIDC_METRICS_COUNTERS); + + /* loop over the individual metrics */ + for (hi2 = apr_hash_first(s->process->pool, server_hash); hi2; hi2 = apr_hash_next(hi2)) { + apr_hash_this(hi2, (const void **)&key, NULL, (void **)&counter); + + /* get or create the corresponding metric entry in the global metrics */ + j_value = json_object_get(j_counters, key); + if (j_value != NULL) { + j_member = json_object_get(j_value, OIDC_METRICS_COUNT); + json_integer_set(j_member, json_integer_value(j_member) + counter->count); + } else { + json_object_set_new(j_counters, key, oidc_metrics_counter_new(s, counter)); + } + } + } + + /* loop over the locally cached metrics from this process */ + for (hi1 = apr_hash_first(s->process->pool, _oidc_metrics.timings); hi1; hi1 = apr_hash_next(hi1)) { + apr_hash_this(hi1, (const void **)&name, NULL, (void **)&server_hash); + + j_server = oidc_metrics_server_get(json, name); + j_timings = json_object_get(j_server, OIDC_METRICS_TIMINGS); + + /* loop over the individual metrics */ + for (hi2 = apr_hash_first(s->process->pool, server_hash); hi2; hi2 = apr_hash_next(hi2)) { + apr_hash_this(hi2, (const void **)&key, NULL, (void **)&timing); + + /* get or create the corresponding metric entry in the global metrics */ + j_value = json_object_get(j_timings, key); + if (j_value != NULL) + oidc_metrics_timings_update(s, j_value, timing); + else + json_object_set_new(j_timings, key, oidc_metrics_timings_new(s, timing)); + } + } + + /* serialize the metrics data, preserve order is required for Prometheus */ + char *str = json_dumps(json, JSON_COMPACT | JSON_PRESERVE_ORDER); + s_json = apr_pstrdup(s->process->pool, str); + free(str); + + /* free the JSON data */ + json_decref(json); + + /* store the serialized metrics data in shared memory */ + oidc_metrics_storage_set(s, s_json); + + /* unlock the shared memory for other processes */ + oidc_cache_mutex_unlock(s->process->pool, s, _oidc_metrics_global_mutex); +} + +/* + * thread that periodically writes the local data into the shared memory + */ +static void *oidc_metrics_thread_run(apr_thread_t *thread, void *data) { + server_rec *s = (server_rec *)data; + + /* see if we are asked to exit */ + while (_oidc_metrics_thread_exit == FALSE) { + + apr_sleep(apr_time_from_sec(OIDC_CACHE_METRICS_STORAGE_INTERVAL)); + // NB: no exit here because we need to write our local metrics into the cache before exiting + + /* lock the mutex that protects the locally cached metrics */ + oidc_cache_mutex_lock(s->process->pool, s, _oidc_metrics_process_mutex); + + /* flush the locally cached metrics into the global shared memory */ + oidc_metrics_store(s); + + /* reset the local hashtables */ + apr_hash_clear(_oidc_metrics.counters); + apr_hash_clear(_oidc_metrics.timings); + + /* unlock the mutex that protects the locally cached metrics */ + oidc_cache_mutex_unlock(s->process->pool, s, _oidc_metrics_process_mutex); + } + + apr_thread_exit(thread, APR_SUCCESS); + + return NULL; +} + +/* + * NB: global, yet called for each vhost that has metrics enabled! + */ +apr_byte_t oidc_metrics_cache_post_config(server_rec *s) { + + /* make sure it gets executed exactly once! */ + if (_oidc_metrics_cache != NULL) + return TRUE; + + /* create the shared memory segment that holds the stringified JSON formatted metrics data */ + if (apr_shm_create(&_oidc_metrics_cache, OIDC_CACHE_METRICS_JSON_MAX, NULL, s->process->pconf) != APR_SUCCESS) + return FALSE; + if (_oidc_metrics_cache == NULL) + return FALSE; + + /* initialize the shared memory segment to 0 */ + char *p = apr_shm_baseaddr_get(_oidc_metrics_cache); + *p = 0; + + /* flag this as the parent, for shared memory cleanup purposes and "multiple child-init calls" detection */ + _oidc_metrics_is_parent = TRUE; + + /* create the thread that will periodically flush the local metrics data to shared memory */ + if (apr_thread_create(&_oidc_metrics_thread, NULL, oidc_metrics_thread_run, s, s->process->pool) != APR_SUCCESS) + return FALSE; + + /* create the hashtable that holds local metrics data */ + _oidc_metrics.counters = apr_hash_make(s->process->pool); + _oidc_metrics.timings = apr_hash_make(s->process->pool); + + /* create and initialize the mutex that guards _oidc_metrics_hash */ + _oidc_metrics_global_mutex = oidc_cache_mutex_create(s->process->pool, TRUE); + if (_oidc_metrics_global_mutex == NULL) + return FALSE; + if (oidc_cache_mutex_post_config(s, _oidc_metrics_global_mutex, "metrics-global") == FALSE) + return FALSE; + + /* create and initialize the mutex that guards the shared memory */ + _oidc_metrics_process_mutex = oidc_cache_mutex_create(s->process->pool, FALSE); + if (_oidc_metrics_process_mutex == NULL) + return FALSE; + if (oidc_cache_mutex_post_config(s, _oidc_metrics_process_mutex, "metrics-process") == FALSE) + return FALSE; + + return TRUE; +} + +/* + * NB: global, yet called for each vhost that has metrics enabled! + */ +apr_status_t oidc_metrics_cache_child_init(apr_pool_t *p, server_rec *s) { + + /* make sure this executes only once per child */ + if (_oidc_metrics_is_parent == FALSE) + return APR_SUCCESS; + + if (oidc_cache_mutex_child_init(p, s, _oidc_metrics_global_mutex) != APR_SUCCESS) + return APR_EGENERAL; + + if (oidc_cache_mutex_child_init(p, s, _oidc_metrics_process_mutex) != APR_SUCCESS) + return APR_EGENERAL; + + /* the metrics flush thread is not inherited from the parent, so re-create it in the child */ + if (apr_thread_create(&_oidc_metrics_thread, NULL, oidc_metrics_thread_run, s, s->process->pool) != APR_SUCCESS) + return APR_EGENERAL; + + /* flag this is a child */ + _oidc_metrics_is_parent = FALSE; + + return APR_SUCCESS; +} + +/* + * NB: global, yet called for each vhost that has metrics enabled! + */ +apr_status_t oidc_metrics_cache_cleanup(server_rec *s) { + + /* make sure it gets executed exactly once! */ + if (_oidc_metrics_cache == NULL) + return APR_SUCCESS; + + /* signal the collector thread to exit and wait (at max 5 seconds) for it to flush its data and exit */ + _oidc_metrics_thread_exit = TRUE; + apr_status_t rv = APR_SUCCESS; + apr_thread_join(&rv, _oidc_metrics_thread); + if (rv != APR_SUCCESS) + return rv; + + /* delete the shared memory segment if we are in the parent process */ + if (_oidc_metrics_is_parent == TRUE) + apr_shm_destroy(_oidc_metrics_cache); + _oidc_metrics_cache = NULL; + + /* delete the process mutex that guards the local metrics data */ + if (oidc_cache_mutex_destroy(s, _oidc_metrics_process_mutex) == FALSE) + return APR_EGENERAL; + + /* delete the process mutex that guards the global shared memory segment */ + if (oidc_cache_mutex_destroy(s, _oidc_metrics_global_mutex) == FALSE) + return APR_EGENERAL; + + return rv; +} + +/* + * obtain the local metrics hashtable for the current vhost + */ +static apr_hash_t *oidc_metrics_server_hash(request_rec *r, apr_hash_t *table) { + apr_hash_t *server_hash = NULL; + char *name = "_default_"; + + /* obtain the vhost name */ + if (r->server->server_hostname) + name = r->server->server_hostname; + + /* get the entry to the vhost record, or newly create it */ + server_hash = apr_hash_get(table, name, APR_HASH_KEY_STRING); + if (server_hash == NULL) { + // NB: process pool! + server_hash = apr_hash_make(r->server->process->pool); + apr_hash_set(table, name, APR_HASH_KEY_STRING, server_hash); + } + + return server_hash; +} + +/* + * retrieve or create a local hashtable for the specified key + * NB: assumes local hashtable has been locked + */ +static void *oidc_metrics_get(request_rec *r, const char *key, apr_hash_t *table, size_t size) { + void *result = NULL; + apr_hash_t *server_hash = oidc_metrics_server_hash(r, table); + + /* get the entry to the specified metric */ + result = apr_hash_get(server_hash, key, APR_HASH_KEY_STRING); + if (result == NULL) { + /* newly create it with the passed value */ + result = apr_pcalloc(r->server->process->pool, size); + // NB: allocate the key in the process pool + apr_hash_set(server_hash, apr_pstrdup(r->server->process->pool, key), APR_HASH_KEY_STRING, result); + } + + return result; +} + +/* + * add/increase a counter metric in the locally cached data + */ +void oidc_metrics_counter_add(request_rec *r, const char *metric_name, const char *label_name, const char *label_value, + const char *desc) { + oidc_metrics_counter_t *counter = NULL; + char *key = NULL; + + /* lock the local metrics cache hashtable */ + oidc_cache_mutex_lock(r->pool, r->server, _oidc_metrics_process_mutex); + + /* obtain or create the entry for the specified key */ + key = apr_psprintf(r->server->process->pool, "%s", metric_name); + if ((label_name) && (_oidc_strcmp(label_name, "") != 0)) { + key = apr_psprintf(r->server->process->pool, "%s.%s", key, label_name); + if ((label_value) && (_oidc_strcmp(label_value, "") != 0)) { + key = apr_psprintf(r->server->process->pool, "%s.%s", key, label_value); + } + } + + counter = + (oidc_metrics_counter_t *)oidc_metrics_get(r, key, _oidc_metrics.counters, sizeof(oidc_metrics_counter_t)); + counter->metric_name = apr_pstrdup(r->server->process->pool, metric_name); + counter->label_name = apr_pstrdup(r->server->process->pool, label_name); + counter->label_value = apr_pstrdup(r->server->process->pool, label_value); + counter->desc = apr_pstrdup(r->server->process->pool, desc); + counter->count++; + + /* unlock the local metrics cache hashtable */ + oidc_cache_mutex_unlock(r->pool, r->server, _oidc_metrics_process_mutex); +} + +/* + * add a metrics timing sample to the locally cached data + */ +void oidc_metrics_timing_add(request_rec *r, const char *key, apr_time_t elapsed, const char *desc) { + oidc_metrics_timing_t *timing = NULL; + int i = 0; + + /* TODO: how can this happen? */ + if (elapsed < 0) { + oidc_warn(r, "discarding metrics timing %s: elapsed (%" APR_TIME_T_FMT ") < 0", key, elapsed); + return; + } + + /* lock the local metrics cache hashtable */ + oidc_cache_mutex_lock(r->pool, r->server, _oidc_metrics_process_mutex); + + /* obtain or create the entry for the specified key */ + timing = oidc_metrics_get(r, key, _oidc_metrics.timings, sizeof(oidc_metrics_timing_t)); + if (timing->buckets == NULL) + timing->buckets = apr_pcalloc(r->server->process->pool, sizeof(json_int_t) * OIDC_METRICS_BUCKET_NUM); + for (i = 0; i < OIDC_METRICS_BUCKET_NUM; i++) + if ((elapsed < _oidc_metric_buckets[i].threshold) || (_oidc_metric_buckets[i].threshold == 0)) + timing->buckets[i]++; + timing->desc = apr_pstrdup(r->server->process->pool, desc); + timing->sum += elapsed; + timing->count++; + + /* unlock the local metrics cache hashtable */ + oidc_cache_mutex_unlock(r->pool, r->server, _oidc_metrics_process_mutex); +} + +static int oidc_metrics_handle_json(request_rec *r, const char *s_json) { + /* return an empty JSON object if no (new) metrics data was found */ + if (s_json == NULL) + s_json = "{}"; + /* return the data to the caller */ + return oidc_util_http_send(r, s_json, _oidc_strlen(s_json), OIDC_CONTENT_TYPE_JSON, OK); +} + +static const char *oidc_metrics_name_to_label(request_rec *r, const char *json_name) { + const char *name = json_name; + int i = 0; + for (i = 0; i < OIDC_METRICS_BUCKET_NUM; i++) { + if (_oidc_strcmp(_oidc_metric_buckets[i].name, json_name) == 0) { + name = _oidc_metric_buckets[i].label; + break; + } + } + return name; +} + +static const char *oidc_prometheus_normalize(request_rec *r, const char *v1, const char *v2) { + char *label = apr_psprintf(r->pool, "%s%s%s", v1 ? v1 : "", v2 ? "_" : "", v2 ? v2 : ""); + int i = 0; + for (i = 0; i < strlen(label); i++) + if ((label[i] == '-') || (label[i] == '.')) + label[i] = '_'; + return label; +} + +static int oidc_metrics_handle_prometheus(request_rec *r, const char *s_json) { + char *s_text = ""; + json_t *json = NULL, *j_server = NULL, *j_timings, *j_counters, *j_timing = NULL, *j_member = NULL, + *j_counter = NULL; + json_error_t json_error; + const char *s_server = NULL, *s_name = NULL, *s_member = NULL, *s_label = NULL, *s_value = NULL, + *s_metric = NULL, *s_desc = NULL; + + /* parse the metrics string to JSON */ + if (s_json != NULL) + json = json_loads(s_json, 0, &json_error); + if (json == NULL) + return OK; + + void *iter1 = json_object_iter(json); + while (iter1) { + s_server = json_object_iter_key(iter1); + j_server = json_object_iter_value(iter1); + + j_counters = json_object_get(j_server, OIDC_METRICS_COUNTERS); + + void *iter2 = json_object_iter(j_counters); + while (iter2) { + s_name = json_object_iter_key(iter2); + j_counter = json_object_iter_value(iter2); + + s_metric = json_string_value(json_object_get(j_counter, OIDC_METRICS_NAME)); + s_desc = json_string_value(json_object_get(j_counter, OIDC_METRICS_DESC)); + + s_label = oidc_prometheus_normalize(r, s_server, s_name); + s_text = apr_psprintf(r->pool, "%s# HELP %s The number of %s.\n", s_text, s_label, s_desc); + s_text = apr_psprintf(r->pool, "%s# TYPE %s counter\n", s_text, s_label); + + s_text = + apr_psprintf(r->pool, "%s%s", s_text, oidc_prometheus_normalize(r, s_server, s_metric)); + j_member = json_object_get(j_counter, OIDC_METRICS_LABEL_NAME); + if (j_member) { + s_label = json_string_value(j_member); + s_value = json_string_value(json_object_get(j_counter, OIDC_METRICS_LABEL_VALUE)); + s_text = apr_psprintf(r->pool, "%s{%s=\"%s\"}", s_text, + oidc_prometheus_normalize(r, s_label, NULL), s_value); + } + j_member = json_object_get(j_counter, "count"); + s_text = apr_psprintf(r->pool, "%s %ld\n", s_text, (long int)json_integer_value(j_member)); + + s_text = apr_psprintf(r->pool, "%s\n", s_text); + + iter2 = json_object_iter_next(j_counters, iter2); + } + + j_timings = json_object_get(j_server, OIDC_METRICS_TIMINGS); + + iter2 = json_object_iter(j_timings); + while (iter2) { + s_name = json_object_iter_key(iter2); + j_timing = json_object_iter_value(iter2); + + s_label = oidc_prometheus_normalize(r, s_server, s_name); + s_desc = json_string_value(json_object_get(j_timing, OIDC_METRICS_DESC)); + s_text = apr_psprintf(r->pool, "%s# HELP %s A histogram of %s.\n", s_text, s_label, s_desc); + s_text = apr_psprintf(r->pool, "%s# TYPE %s histogram\n", s_text, s_label); + + void *iter3 = json_object_iter(j_timing); + while (iter3) { + s_member = json_object_iter_key(iter3); + j_member = json_object_iter_value(iter3); + s_text = apr_psprintf(r->pool, "%s%s_%s %ld\n", s_text, s_label, + oidc_metrics_name_to_label(r, s_member), + (long int)json_integer_value(j_member)); + iter3 = json_object_iter_next(j_timing, iter3); + } + s_text = apr_psprintf(r->pool, "%s\n", s_text); + + iter2 = json_object_iter_next(j_timings, iter2); + } + iter1 = json_object_iter_next(json, iter1); + + s_text = apr_psprintf(r->pool, "%s\n\n", s_text); + } + + json_decref(json); + + return oidc_util_http_send(r, s_text, _oidc_strlen(s_text), "text/plain; version=0.0.4", OK); +} + +#define OIDC_METRICS_FORMAT_PARAM "format" +#define OIDC_METRICS_FORMAT_JSON "json" +#define OIDC_METRICS_FORMAT_PROMETHEUS "prometheus" + +/* + * return the metrics to the caller and flush the storage + */ +int oidc_metrics_handle_request(request_rec *r) { + char *s_format = NULL; + char *s_json = NULL; + char *s_content_type = NULL; + + /* lock the global shared memory */ + oidc_cache_mutex_lock(r->pool, r->server, _oidc_metrics_global_mutex); + + /* retrieve the JSON formatted metrics as a string */ + oidc_metrics_storage_get(r->server, &s_json); + + /* now that the metrics have been consumed, clear the shared memory segment */ + oidc_metrics_storage_set(r->server, NULL); + + /* unlock the global shared memory */ + oidc_cache_mutex_unlock(r->pool, r->server, _oidc_metrics_global_mutex); + + /* handle specified format */ + oidc_util_get_request_parameter(r, OIDC_METRICS_FORMAT_PARAM, &s_format); + if (_oidc_strcmp(s_format, OIDC_METRICS_FORMAT_JSON) == 0) + return oidc_metrics_handle_json(r, s_json); + + return oidc_metrics_handle_prometheus(r, s_json); +} diff --git a/src/metrics.h b/src/metrics.h new file mode 100644 index 00000000..a39da92d --- /dev/null +++ b/src/metrics.h @@ -0,0 +1,72 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +/*************************************************************************** + * Copyright (C) 2017-2023 ZmartZone Holding BV + * Copyright (C) 2013-2017 Ping Identity Corporation + * All rights reserved. + * + * DISCLAIMER OF WARRANTIES: + * + * THE SOFTWARE PROVIDED HEREUNDER IS PROVIDED ON AN "AS IS" BASIS, WITHOUT + * ANY WARRANTIES OR REPRESENTATIONS EXPRESS, IMPLIED OR STATUTORY; INCLUDING, + * WITHOUT LIMITATION, WARRANTIES OF QUALITY, PERFORMANCE, NONINFRINGEMENT, + * MERCHANTABILITY OR FITNESS FOR A PARTICULAR PURPOSE. NOR ARE THERE ANY + * WARRANTIES CREATED BY A COURSE OR DEALING, COURSE OF PERFORMANCE OR TRADE + * USAGE. FURTHERMORE, THERE ARE NO WARRANTIES THAT THE SOFTWARE WILL MEET + * YOUR NEEDS OR BE FREE FROM ERRORS, OR THAT THE OPERATION OF THE SOFTWARE + * WILL BE UNINTERRUPTED. IN NO EVENT SHALL THE COPYRIGHT HOLDERS OR + * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, + * EXEMPLARY, OR CONSEQUENTIAL DAMAGES HOWEVER CAUSED AND ON ANY THEORY OF + * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING + * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS + * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + * @Author: Hans Zandbelt - hans.zandbelt@openidc.com + */ + +#ifndef MOD_AUTH_OPENIDC_METRICS_H_ +#define MOD_AUTH_OPENIDC_METRICS_H_ + +apr_byte_t oidc_metrics_cache_post_config(server_rec *s); +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); +void oidc_metrics_counter_add(request_rec *r, const char *metric_name, const char *label_name, const char *label_value, + const char *desc); +void oidc_metrics_timing_add(request_rec *r, const char *key, apr_time_t elapsed, const char *desc); + +#define OIDC_METRICS_TIMING_START(r, cfg) \ + apr_time_t _oidc_metrics_tstart; \ + if (cfg->metrics_hook_data != NULL) \ + _oidc_metrics_tstart = apr_time_now(); + +#define OIDC_METRICS_TIMING_ADD(r, cfg, main_key, sub_key, desc) \ + if (cfg->metrics_hook_data != NULL) \ + if (apr_hash_get(cfg->metrics_hook_data, main_key, APR_HASH_KEY_STRING) != NULL) { \ + oidc_metrics_timing_add(r, apr_psprintf(r->pool, "%s.%s", main_key, sub_key), \ + apr_time_now() - _oidc_metrics_tstart, desc); \ + } + +#define OIDC_METRICS_COUNTER_ADD(r, cfg, metric_name, label_name, label_value, desc) \ + if (cfg->metrics_hook_data != NULL) \ + if (apr_hash_get(cfg->metrics_hook_data, metric_name, APR_HASH_KEY_STRING) != NULL) \ + oidc_metrics_counter_add(r, metric_name, label_name, label_value, desc); + +#endif /* MOD_AUTH_OPENIDC_METRICS_H_ */ diff --git a/src/mod_auth_openidc.c b/src/mod_auth_openidc.c index 053050ed..afbb546f 100644 --- a/src/mod_auth_openidc.c +++ b/src/mod_auth_openidc.c @@ -50,6 +50,8 @@ #include "mod_auth_openidc.h" +#include "metrics.h" + static int oidc_handle_logout_request(request_rec *r, oidc_cfg *c, oidc_session_t *session, const char *url); // TODO: @@ -1640,6 +1642,8 @@ static int oidc_handle_existing_session(request_rec *r, oidc_cfg *cfg, oidc_sess /* verify current cookie domain against issued cookie domain */ if (oidc_check_cookie_domain(r, cfg, session) == FALSE) { *needs_save = FALSE; + OIDC_METRICS_COUNTER_ADD(r, cfg, "session", "error", "cookie-domain", + "cookie domain validation errors for existing sessions") return HTTP_UNAUTHORIZED; } @@ -1654,6 +1658,8 @@ static int oidc_handle_existing_session(request_rec *r, oidc_cfg *cfg, oidc_sess if (oidc_check_max_session_duration(r, cfg, session, &rc) == FALSE) { *needs_save = FALSE; // NB: rc was set (e.g. to a 302 auth redirect) by the call to oidc_check_max_session_duration + OIDC_METRICS_COUNTER_ADD(r, cfg, "session", "error", "expired", + "sessions that exceeded the maximum duration") return rc; } @@ -1663,6 +1669,8 @@ static int oidc_handle_existing_session(request_rec *r, oidc_cfg *cfg, oidc_sess if (rv == FALSE) { *needs_save = FALSE; oidc_debug(r, "dir_action_on_error_refresh: %d", oidc_cfg_dir_action_on_error_refresh(r)); + OIDC_METRICS_COUNTER_ADD(r, cfg, "session", "error", "refresh-access-token", + "errors refreshing the access token before expiry in existing sessions") if (error_code != OIDC_REFRESH_ERROR_PARALLEL_REFRESH) { if (oidc_cfg_dir_action_on_error_refresh(r) == OIDC_ON_ERROR_LOGOUT) { return oidc_handle_logout_request(r, cfg, session, @@ -1681,6 +1689,8 @@ static int oidc_handle_existing_session(request_rec *r, oidc_cfg *cfg, oidc_sess if (rv == FALSE) { *needs_save = FALSE; oidc_debug(r, "action_on_userinfo_error: %d", cfg->action_on_userinfo_error); + OIDC_METRICS_COUNTER_ADD(r, cfg, "session", "error", "refresh-user-info", + "errors refreshing claims from the userinfo endpoint in existing sessions") if (error_code != OIDC_REFRESH_ERROR_PARALLEL_REFRESH) { if (cfg->action_on_userinfo_error == OIDC_ON_ERROR_LOGOUT) { return oidc_handle_logout_request(r, cfg, session, @@ -2111,6 +2121,8 @@ static int oidc_handle_authorization_response(request_rec *r, oidc_cfg *c, oidc_ "there: %s", c->default_sso_url); oidc_util_hdr_out_location_set(r, oidc_get_absolute_url(r, c, c->default_sso_url)); + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "state-mismatch", + "state mismatch errors in authentication responses") return HTTP_MOVED_TEMPORARILY; } oidc_error(r, @@ -2128,8 +2140,14 @@ static int oidc_handle_authorization_response(request_rec *r, oidc_cfg *c, oidc_ } // if error text was already produced (e.g. state timeout) then just return with a 400 - if (apr_table_get(r->subprocess_env, OIDC_ERROR_ENVVAR) != NULL) + if (apr_table_get(r->subprocess_env, OIDC_ERROR_ENVVAR) != NULL) { + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "state-expired", + "state expired errors in authentication responses") return HTTP_BAD_REQUEST; + } + + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "state-mismatch", + "state expired errors in authentication responses") return oidc_util_html_send_error(r, c->error_template, "Invalid Authorization Response", "Could not match the authorization response to an earlier request via " @@ -2138,13 +2156,19 @@ static int oidc_handle_authorization_response(request_rec *r, oidc_cfg *c, oidc_ } /* see if the response is an error response */ - if (apr_table_get(params, OIDC_PROTO_ERROR) != NULL) + if (apr_table_get(params, OIDC_PROTO_ERROR) != NULL) { + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "provider", + "errors returned by the provider in authentication responses") return oidc_authorization_response_error(r, c, proto_state, apr_table_get(params, OIDC_PROTO_ERROR), apr_table_get(params, OIDC_PROTO_ERROR_DESCRIPTION)); + } /* handle the code, implicit or hybrid flow */ - if (oidc_handle_flows(r, c, proto_state, provider, params, response_mode, &jwt) == FALSE) + if (oidc_handle_flows(r, c, proto_state, provider, params, response_mode, &jwt) == FALSE) { + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "protocol", + "errors handling authentication responses") return oidc_authorization_response_error(r, c, proto_state, "Error in handling response type.", NULL); + } if (jwt == NULL) { oidc_error(r, "no id_token was provided"); @@ -2205,6 +2229,8 @@ static int oidc_handle_authorization_response(request_rec *r, oidc_cfg *c, oidc_ } else { oidc_error(r, "remote user could not be set"); oidc_jwt_destroy(jwt); + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "remote-user", + "errors identifying the remote user based on provided claims") return oidc_authorization_response_error( r, c, proto_state, "Remote user could not be set: contact the website administrator", NULL); } @@ -2214,8 +2240,11 @@ static int oidc_handle_authorization_response(request_rec *r, oidc_cfg *c, oidc_ oidc_jwt_destroy(jwt); /* check that we've actually authenticated a user; functions as error handling for oidc_get_remote_user */ - if (r->user == NULL) + if (r->user == NULL) { + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "response.error", "remote-user", + "errors identifying the remote user based on provided claims") return HTTP_UNAUTHORIZED; + } /* log the successful response */ oidc_debug(r, "session created and stored, returning to original URL: %s, original method: %s", original_url, @@ -2430,6 +2459,8 @@ static int oidc_authenticate_user(request_rec *r, oidc_cfg *c, oidc_provider_t * int rc; + OIDC_METRICS_TIMING_START(r, c) + oidc_debug(r, "enter"); if (provider == NULL) { @@ -2444,13 +2475,17 @@ static int oidc_authenticate_user(request_rec *r, oidc_cfg *c, oidc_provider_t * oidc_request_state_set(r, OIDC_REQUEST_STATE_KEY_DISCOVERY, ""); oidc_debug(r, "defer discovery to the content handler, setting r->user=\"\""); r->user = ""; + return OK; } /* we're not using multiple OP's configured in a metadata directory, pick the statically configured OP */ - if (oidc_provider_static_config(r, c, &provider) == FALSE) + if (oidc_provider_static_config(r, c, &provider) == FALSE) { + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "request.error", "provider-config", + "errors retrieving/parsing the provider configuration") return HTTP_INTERNAL_SERVER_ERROR; + } } /* generate the random nonce value that correlates requests and responses */ @@ -2539,6 +2574,9 @@ static int oidc_authenticate_user(request_rec *r, oidc_cfg *c, oidc_provider_t * "\"state\" and \"session\" cookies will not be shared between the two!", r_uri.hostname, o_uri.hostname); oidc_proto_state_destroy(proto_state); + OIDC_METRICS_COUNTER_ADD( + r, c, "authn", "request.error", "url", + "errors matching the incoming request URL against the configuration") return HTTP_INTERNAL_SERVER_ERROR; } } @@ -2550,15 +2588,21 @@ static int oidc_authenticate_user(request_rec *r, oidc_cfg *c, oidc_provider_t * "\"state\" and \"session\" cookies will not work!!", c->cookie_domain, o_uri.hostname, original_url); oidc_proto_state_destroy(proto_state); + OIDC_METRICS_COUNTER_ADD(r, c, "authn", "request.error", "url", + "errors matching the incoming request URL against the configuration") return HTTP_INTERNAL_SERVER_ERROR; } } /* send off to the OpenID Connect Provider */ // TODO: maybe show intermediate/progress screen "redirecting to" - return oidc_proto_authorization_request(r, provider, login_hint, oidc_get_redirect_uri_iss(r, c, provider), - state, proto_state, id_token_hint, code_challenge, auth_request_params, - path_scope); + rc = oidc_proto_authorization_request(r, provider, login_hint, oidc_get_redirect_uri_iss(r, c, provider), state, + proto_state, id_token_hint, code_challenge, auth_request_params, + path_scope); + + OIDC_METRICS_TIMING_ADD(r, c, "authn", "request", "authentication requests") + + return rc; } /* @@ -3900,10 +3944,19 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t apr_byte_t needs_save = FALSE; int rc = OK; + OIDC_METRICS_TIMING_START(r, c) + if (oidc_proto_is_redirect_authorization_response(r, c)) { /* this is an authorization response from the OP using the Basic Client profile or a Hybrid flow*/ - return oidc_handle_redirect_authorization_response(r, c, session); + rc = oidc_handle_redirect_authorization_response(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "authn.response", "redirect", + "authentication responses received in a redirect"); + OIDC_METRICS_TIMING_ADD(r, c, "authn", "response", "authentication responses") + + return rc; + /* * * Note that we are checking for logout *before* checking for a POST authorization response @@ -3915,18 +3968,34 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t */ } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_LOGOUT)) { /* handle logout */ - return oidc_handle_logout(r, c, session); + rc = oidc_handle_logout(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_LOGOUT, + "logout requests to the redirect URI"); + + return rc; } else if (oidc_proto_is_post_authorization_response(r, c)) { /* this is an authorization response using the fragment(+POST) response_mode with the Implicit Client * profile */ - return oidc_handle_post_authorization_response(r, c, session); + rc = oidc_handle_post_authorization_response(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "authn.response", "post", + "authentication responses received in a HTTP POST"); + OIDC_METRICS_TIMING_ADD(r, c, "authn", "response", "authentication responses") + + return rc; } else if (oidc_is_discovery_response(r, c)) { /* this is response from the OP discovery page */ - return oidc_handle_discovery_response(r, c); + rc = oidc_handle_discovery_response(r, c); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "discovery", "response", + "discovery responses to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_JWKS)) { /* @@ -3935,32 +4004,61 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t * by setting r->user */ r->user = ""; + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", "jwks", + "JWKs retrieval requests to the redirect URI"); + return OK; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_SESSION)) { /* handle session management request */ - return oidc_handle_session_management(r, c, session); + rc = oidc_handle_session_management(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_SESSION, + "session management requests to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_REFRESH)) { /* handle refresh token request */ - return oidc_handle_refresh_token_request(r, c, session); + rc = oidc_handle_refresh_token_request(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_REFRESH, + "refresh token requests to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_REQUEST_URI)) { /* handle request object by reference request */ - return oidc_handle_request_uri(r, c); + rc = oidc_handle_request_uri(r, c); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_REQUEST_URI, + "Request URI calls to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_REMOVE_AT_CACHE)) { /* handle request to invalidate access token cache */ - return oidc_handle_remove_at_cache(r, c); + rc = oidc_handle_remove_at_cache(r, c); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_REMOVE_AT_CACHE, + "access token cache removal requests to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_REVOKE_SESSION)) { /* handle request to revoke a user session */ - return oidc_handle_revoke_session(r, c); + rc = oidc_handle_revoke_session(r, c); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_REVOKE_SESSION, + "revoke session requests to the redirect URI"); + + return rc; } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_INFO)) { @@ -3978,13 +4076,21 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t if (needs_save) oidc_request_state_set(r, OIDC_REQUEST_STATE_KEY_SAVE, ""); + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "request", OIDC_REDIRECT_URI_REQUEST_INFO, + "info hook requests to the redirect URI"); + return rc; } else if ((r->args == NULL) || (_oidc_strcmp(r->args, "") == 0)) { /* this is a "bare" request to the redirect URI, indicating implicit flow using the fragment * response_mode */ - return oidc_proto_javascript_implicit(r, c); + rc = oidc_proto_javascript_implicit(r, c); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "authn.response", "implicit", + "(presumed) implicit authentication responses to the redirect URI"); + + return rc; } /* this is not an authorization response or logout request */ @@ -3998,13 +4104,20 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t // // /* send user facing error to browser */ // return oidc_util_html_send_error(r, error, descr, OK); - return oidc_handle_redirect_authorization_response(r, c, session); + rc = oidc_handle_redirect_authorization_response(r, c, session); + + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "error", "provider", + "provider authentication response errors received on the redirect URI"); + + return rc; } oidc_error( r, "The OpenID Connect callback URL received an invalid request: %s; returning HTTP_INTERNAL_SERVER_ERROR", r->args); + OIDC_METRICS_COUNTER_ADD(r, c, "redirect_uri", "error", "invalid", "invalid requests to the redirect URI"); + /* something went wrong */ return oidc_util_html_send_error( r, c->error_template, "Invalid Request", @@ -4021,6 +4134,8 @@ int oidc_handle_redirect_uri_request(request_rec *r, oidc_cfg *c, oidc_session_t */ static int oidc_check_userid_openidc(request_rec *r, oidc_cfg *c) { + OIDC_METRICS_TIMING_START(r, c); + if (oidc_get_redirect_uri(r, c) == NULL) { oidc_error(r, "configuration error: the authentication type is set to \"" OIDC_AUTH_TYPE_OPENID_CONNECT "\" but " OIDCRedirectURI " has not been set"); @@ -4113,6 +4228,13 @@ static int oidc_check_userid_openidc(request_rec *r, oidc_cfg *c) { /* strip any cookies that we need to */ oidc_strip_cookies(r); + if (rc == OK) { + OIDC_METRICS_TIMING_ADD(r, c, "session", "valid", "successfully validated existing sessions") + } else { + OIDC_METRICS_COUNTER_ADD(r, c, "session", "error", "generic", + "existing sessions that failed validation") + } + return rc; } @@ -4156,36 +4278,39 @@ static int oidc_check_mixed_userid_oauth(request_rec *r, oidc_cfg *c) { int oidc_check_user_id(request_rec *r) { oidc_cfg *c = ap_get_module_config(r->server->module_config, &auth_openidc_module); + int rv = DECLINED; + const char *current_auth = NULL; /* log some stuff about the incoming HTTP request */ oidc_debug(r, "incoming request: \"%s?%s\", ap_is_initial_req(r)=%d", r->parsed_uri.path, r->args, ap_is_initial_req(r)); /* see if any authentication has been defined at all */ - const char *current_auth = ap_auth_type(r); + current_auth = ap_auth_type(r); if (current_auth == NULL) - return DECLINED; + current_auth = "declined"; /* see if we've configured OpenID Connect user authentication for this request */ if (strcasecmp(current_auth, OIDC_AUTH_TYPE_OPENID_CONNECT) == 0) { r->ap_auth_type = (char *)current_auth; - return oidc_check_userid_openidc(r, c); - } + rv = oidc_check_userid_openidc(r, c); - /* see if we've configured OAuth 2.0 access control for this request */ - if (strcasecmp(current_auth, OIDC_AUTH_TYPE_OPENID_OAUTH20) == 0) { + /* see if we've configured OAuth 2.0 access control for this request */ + } else if (strcasecmp(current_auth, OIDC_AUTH_TYPE_OPENID_OAUTH20) == 0) { r->ap_auth_type = (char *)current_auth; - return oidc_oauth_check_userid(r, c, NULL); + rv = oidc_oauth_check_userid(r, c, NULL); + + /* see if we've configured "mixed mode" for this request */ + } else if (strcasecmp(current_auth, OIDC_AUTH_TYPE_OPENID_BOTH) == 0) { + + rv = oidc_check_mixed_userid_oauth(r, c); } - /* see if we've configured "mixed mode" for this request */ - if (strcasecmp(current_auth, OIDC_AUTH_TYPE_OPENID_BOTH) == 0) - return oidc_check_mixed_userid_oauth(r, c); + OIDC_METRICS_COUNTER_ADD(r, c, "authtype", "handler", current_auth, "incoming requests"); - /* this is not for us but for some other handler */ - return DECLINED; + return rv; } /* @@ -4445,8 +4570,15 @@ int oidc_content_handler(request_rec *r) { apr_byte_t needs_save = FALSE; oidc_session_t *session = NULL; - if (oidc_enabled(r) == FALSE) + if ((r->parsed_uri.path != NULL) && (c->metrics_path != NULL)) + if (_oidc_strcmp(r->parsed_uri.path, c->metrics_path) == 0) + return oidc_metrics_handle_request(r); + + if (oidc_enabled(r) == FALSE) { + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "declined", + "requests declined by the content handler") return DECLINED; + } if (oidc_util_request_matches_url(r, oidc_get_redirect_uri(r, c)) == TRUE) { @@ -4455,6 +4587,9 @@ int oidc_content_handler(request_rec *r) { if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_INFO)) { + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "info", + "info hook requests to the content handler") + /* see if a session was retained in the request state */ apr_pool_userdata_get((void **)&session, OIDC_USERDATA_SESSION, r->pool); @@ -4476,20 +4611,35 @@ int oidc_content_handler(request_rec *r) { } else if (oidc_util_request_has_parameter(r, OIDC_REDIRECT_URI_REQUEST_JWKS)) { + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "jwks", + "JWKs requests to the content handler") + /* handle JWKs request */ rc = oidc_handle_jwks(r, c); + + } else { + + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "unknown", + "unknown requests to the content handler") } } else if (oidc_request_state_get(r, OIDC_REQUEST_STATE_KEY_DISCOVERY) != NULL) { + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "discovery", + "discovery requests to the content handler") + /* discovery may result in a 200 HTML page or a redirect to an external URL */ rc = oidc_discovery(r, c); } else if (oidc_request_state_get(r, OIDC_REQUEST_STATE_KEY_AUTHN) != NULL) { + OIDC_METRICS_COUNTER_ADD(r, c, "content", "request", "post-preserve", + "POST-preservation requests to the content handler") + /* sending POST preserve */ rc = OK; - } + + } /* else: an authenticated request for which content is produced downstream */ return rc; } diff --git a/src/mod_auth_openidc.h b/src/mod_auth_openidc.h index e5578516..71212d1e 100644 --- a/src/mod_auth_openidc.h +++ b/src/mod_auth_openidc.h @@ -510,6 +510,8 @@ typedef struct oidc_cfg { int provider_metadata_refresh_interval; apr_hash_t *info_hook_data; + apr_hash_t *metrics_hook_data; + char *metrics_path; apr_hash_t *black_listed_claims; apr_hash_t *white_listed_claims; @@ -839,6 +841,8 @@ int oidc_oauth_return_www_authenticate(request_rec *r, const char *error, const #define OIDCRedisCacheServer "OIDCRedisCacheServer" #define OIDCCookiePath "OIDCCookiePath" #define OIDCInfoHook "OIDCInfoHook" +#define OIDCMetricsData "OIDCMetricsData" +#define OIDCMetricsPublish "OIDCMetricsPublish" #define OIDCWhiteListedClaims "OIDCWhiteListedClaims" #define OIDCCryptoPassphrase "OIDCCryptoPassphrase"