From c156ca86ea2674c058d5ceac448339540baa0ddf Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 09:04:16 -0400 Subject: [PATCH 01/16] Add the metrics shared memory block dims_metrics_init creates it in post config, before the first fork, and sizes it from AP_MPMQ_HARD_LIMIT_DAEMONS. dims_metrics_child_init claims a process slot. The block holds the counters, the histograms, and one slot per child. The index maps turn a status, a response code, and an image format into a slot, and hold every value outside their list in the last one. Nothing reads the block yet. --- CMakeLists.txt | 1 + src/metrics.c | 295 +++++++++++++++++++++++++++++++++++++++++++++++++ src/metrics.h | 122 ++++++++++++++++++++ src/module.c | 8 ++ 4 files changed, 426 insertions(+) create mode 100644 src/metrics.c create mode 100644 src/metrics.h diff --git a/CMakeLists.txt b/CMakeLists.txt index c6088fe..4ba6734 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -82,6 +82,7 @@ add_library(mod_dims MODULE src/signature.c src/svgguard.c src/url.c + src/metrics.c src/status.c src/mod_dims.c src/module.c diff --git a/src/metrics.c b/src/metrics.c new file mode 100644 index 0000000..0f1b4c7 --- /dev/null +++ b/src/metrics.c @@ -0,0 +1,295 @@ +/* + * The metrics block, shared by every worker. + * + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "metrics.h" +#include "module.h" + +#include +#include + +dims_metrics_rec *dims_metrics; + +static apr_shm_t *metrics_shm; + +/* The slot this child claimed in dims_metrics_child_init. */ +static dims_process_rec *my_process; + +static const double duration_bound[] = { + 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10 +}; + +static const double byte_bound[] = { + 16384, 65536, 262144, 1048576, 4194304, 16777216, 67108864 +}; + +static const double frame_bound[] = { + 1, 2, 4, 8, 16, 32, 64, 128 +}; + +const dims_bucket_spec dims_duration_buckets = { + duration_bound, (int) (sizeof(duration_bound) / sizeof(duration_bound[0])) +}; + +const dims_bucket_spec dims_byte_buckets = { + byte_bound, (int) (sizeof(byte_bound) / sizeof(byte_bound[0])) +}; + +const dims_bucket_spec dims_frame_buckets = { + frame_bound, (int) (sizeof(frame_bound) / sizeof(frame_bound[0])) +}; + +/* Indexed by dims_endpoint_t. */ +static const char *const endpoint_name[] = { + "dims3", "dims4", "dims5", "local" +}; + +/* Indexed by dims_status_t, which starts at DIMS_SUCCESS. */ +static const char *const outcome_name[DIMS_OUTCOME_COUNT] = { + "success", + "failure", + "download_timeout", + "imagemagick_timeout", + "bad_client", + "bad_url", + "bad_arguments", + "hostname_not_in_whitelist", + "file_not_found", + "network_refused" +}; + +static const int code_value[DIMS_CODE_COUNT - 1] = { + 200, 400, 403, 404, 429, 500, 502, 503, 504 +}; + +static const char *const code_name[DIMS_CODE_COUNT] = { + "200", "400", "403", "404", "429", "500", "502", "503", "504", "other" +}; + +static const int origin_code_value[DIMS_ORIGIN_CODE_COUNT - 1] = { + 200, 301, 302, 304, 400, 403, 404, 429, 500, 502, 503, 504 +}; + +static const char *const origin_code_name[DIMS_ORIGIN_CODE_COUNT] = { + "200", "301", "302", "304", "400", "403", "404", "429", + "500", "502", "503", "504", "other" +}; + +static const char *const format_name[DIMS_FORMAT_COUNT] = { + "jpeg", "png", "gif", "webp", "avif", "heic", "tiff", "svg", "other" +}; + +apr_status_t +dims_metrics_init(apr_pool_t *p, server_rec *s) +{ + apr_status_t status; + apr_size_t size; + int daemons = 0; + + if (ap_mpm_query(AP_MPMQ_HARD_LIMIT_DAEMONS, &daemons) != APR_SUCCESS || + daemons < 1) { + daemons = 1; + } + + size = sizeof(dims_metrics_rec) + + ((apr_size_t) daemons * sizeof(dims_process_rec)); + + status = apr_shm_create(&metrics_shm, size, NULL, p); + if (status != APR_SUCCESS) { + ap_log_error(APLOG_MARK, APLOG_ERR, status, s, + "mod_dims: the metrics block was not created"); + return status; + } + + dims_metrics = apr_shm_baseaddr_get(metrics_shm); + if (dims_metrics == NULL) { + ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, + "mod_dims: the metrics block has no address"); + return APR_EGENERAL; + } + + memset(dims_metrics, 0, size); + dims_metrics->process_slots = (apr_uint32_t) daemons; + + ap_log_error(APLOG_MARK, APLOG_INFO, 0, s, + "mod_dims: the metrics block is %" APR_SIZE_T_FMT " bytes, " + "with %d process slots", size, daemons); + + return APR_SUCCESS; +} + +void +dims_metrics_child_init(void) +{ + apr_uint32_t i; + apr_uint64_t pid; + + if (dims_metrics == NULL) { + return; + } + + pid = (apr_uint64_t) getpid(); + + /* The first slot holding zero, or a slot left by a child that died. A + * losing compare and swap means another child took it, so try the next. */ + for (i = 0; i < dims_metrics->process_slots; i++) { + dims_process_rec *slot = &dims_metrics->process[i]; + + if (apr_atomic_cas32((apr_uint32_t *) &slot->pid, (apr_uint32_t) pid, + 0) == 0) { + slot->resident_bytes = 0; + slot->virtual_bytes = 0; + memset(slot->imagemagick_resource, 0, + sizeof(slot->imagemagick_resource)); + my_process = slot; + return; + } + } +} + +dims_process_rec * +dims_metrics_process(void) +{ + return my_process; +} + +int +dims_metrics_outcome_index(int status) +{ + if (status < DIMS_SUCCESS || status >= DIMS_OUTCOME_COUNT) { + return DIMS_OUTCOME_COUNT - 1; + } + + return status; +} + +int +dims_metrics_code_index(int code) +{ + int i; + + for (i = 0; i < DIMS_CODE_COUNT - 1; i++) { + if (code_value[i] == code) { + return i; + } + } + + return DIMS_CODE_COUNT - 1; +} + +int +dims_metrics_origin_code_index(int code) +{ + int i; + + for (i = 0; i < DIMS_ORIGIN_CODE_COUNT - 1; i++) { + if (origin_code_value[i] == code) { + return i; + } + } + + return DIMS_ORIGIN_CODE_COUNT - 1; +} + +int +dims_metrics_format_index(const char *format) +{ + int i; + + if (format == NULL) { + return DIMS_FORMAT_COUNT - 1; + } + + /* ImageMagick reports JPG for a JPEG, and the two name one format. */ + if (strcasecmp(format, "jpg") == 0) { + return 0; + } + + for (i = 0; i < DIMS_FORMAT_COUNT - 1; i++) { + if (strcasecmp(format_name[i], format) == 0) { + return i; + } + } + + return DIMS_FORMAT_COUNT - 1; +} + +const char * +dims_metrics_endpoint_name(int index) +{ + if (index < 0 || index >= DIMS_ENDPOINT_COUNT) { + return ""; + } + + return endpoint_name[index]; +} + +const char * +dims_metrics_outcome_name(int index) +{ + if (index < 0 || index >= DIMS_OUTCOME_COUNT) { + return ""; + } + + return outcome_name[index]; +} + +const char * +dims_metrics_code_name(int index) +{ + if (index < 0 || index >= DIMS_CODE_COUNT) { + return ""; + } + + return code_name[index]; +} + +const char * +dims_metrics_origin_code_name(int index) +{ + if (index < 0 || index >= DIMS_ORIGIN_CODE_COUNT) { + return ""; + } + + return origin_code_name[index]; +} + +const char * +dims_metrics_format_name(int index) +{ + if (index < 0 || index >= DIMS_FORMAT_COUNT) { + return ""; + } + + return format_name[index]; +} + +int +dims_metrics_bucket_index(const dims_bucket_spec *spec, double value) +{ + int i; + + for (i = 0; i < spec->bounds; i++) { + if (value <= spec->bound[i]) { + return i; + } + } + + return spec->bounds; +} + +void +dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, + apr_uint64_t value) +{ + double scaled = (spec == &dims_duration_buckets) + ? (double) value / 1000000.0 + : (double) value; + + apr_atomic_inc64(&h->bucket[dims_metrics_bucket_index(spec, scaled)]); + apr_atomic_add64(&h->sum, value); + apr_atomic_inc64(&h->count); +} diff --git a/src/metrics.h b/src/metrics.h new file mode 100644 index 0000000..12b0b4a --- /dev/null +++ b/src/metrics.h @@ -0,0 +1,122 @@ +/* + * The metrics block, shared by every worker. + * + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#ifndef _DIMS_METRICS_H +#define _DIMS_METRICS_H + +#include "mod_dims.h" + +/* The endpoint a request arrived on. */ +typedef enum { + DIMS_ENDPOINT_DIMS3 = 0, + DIMS_ENDPOINT_DIMS4, + DIMS_ENDPOINT_DIMS5, + DIMS_ENDPOINT_LOCAL, + DIMS_ENDPOINT_COUNT +} dims_endpoint_t; + +/* One slot per dims_status_t, without DIMS_IGNORE. */ +#define DIMS_OUTCOME_COUNT 10 + +/* + * Response and origin status codes are reported by name from a list, because + * DimsOriginStatusMode forward copies whatever the origin returned. The last + * slot of each holds every code outside its list. + */ +#define DIMS_CODE_COUNT 10 +#define DIMS_ORIGIN_CODE_COUNT 13 + +/* Image formats reported by name. The last slot holds every other format. */ +#define DIMS_FORMAT_COUNT 9 + +/* The widest bucket table below, plus the +Inf bucket. */ +#define DIMS_BUCKET_MAX 13 + +typedef struct { + apr_uint64_t bucket[DIMS_BUCKET_MAX]; + apr_uint64_t sum; + apr_uint64_t count; +} dims_histogram_rec; + +/* + * A bucket table. bound holds the finite upper bounds in ascending order, and + * the table has bounds + 1 buckets, because the last one is +Inf. + */ +typedef struct { + const double *bound; + int bounds; +} dims_bucket_spec; + +extern const dims_bucket_spec dims_duration_buckets; +extern const dims_bucket_spec dims_byte_buckets; +extern const dims_bucket_spec dims_frame_buckets; + +/* One per child. A child writes only the slot it claimed. */ +typedef struct { + apr_uint64_t pid; + apr_uint64_t resident_bytes; + apr_uint64_t virtual_bytes; + apr_uint64_t imagemagick_resource[4]; +} dims_process_rec; + +typedef struct { + apr_uint64_t requests[DIMS_ENDPOINT_COUNT][DIMS_OUTCOME_COUNT]; + apr_uint64_t responses[DIMS_ENDPOINT_COUNT][DIMS_CODE_COUNT]; + apr_uint64_t in_flight[DIMS_ENDPOINT_COUNT]; + apr_uint64_t origin_responses[DIMS_ORIGIN_CODE_COUNT]; + apr_uint64_t source_format[DIMS_FORMAT_COUNT]; + apr_uint64_t output_format[DIMS_FORMAT_COUNT]; + apr_uint64_t source_bytes_total; + apr_uint64_t output_bytes_total; + + dims_histogram_rec request_duration[DIMS_ENDPOINT_COUNT]; + dims_histogram_rec download_duration; + dims_histogram_rec imagemagick_duration; + dims_histogram_rec source_bytes; + dims_histogram_rec output_bytes; + dims_histogram_rec source_frames; + + /* The slot count comes from AP_MPMQ_HARD_LIMIT_DAEMONS. */ + apr_uint32_t process_slots; + dims_process_rec process[]; +} dims_metrics_rec; + +extern dims_metrics_rec *dims_metrics; + +/* Creates the block. Runs from dims_init, after apr_atomic_init. */ +apr_status_t dims_metrics_init(apr_pool_t *p, server_rec *s); + +/* Claims a process slot. Runs from dims_child_init. */ +void dims_metrics_child_init(void); + +/* The slot this child claimed, or NULL before it claimed one. */ +dims_process_rec *dims_metrics_process(void); + +/* + * Index lookups. Each returns a slot in the matching table, and the last slot + * for a value outside the list. + */ +int dims_metrics_outcome_index(int status); +int dims_metrics_code_index(int code); +int dims_metrics_origin_code_index(int code); +int dims_metrics_format_index(const char *format); + +/* The names the exposition writer prints for each index. */ +const char *dims_metrics_endpoint_name(int index); +const char *dims_metrics_outcome_name(int index); +const char *dims_metrics_code_name(int index); +const char *dims_metrics_origin_code_name(int index); +const char *dims_metrics_format_name(int index); + +/* The bucket a value belongs in, counting the +Inf bucket as spec->bounds. */ +int dims_metrics_bucket_index(const dims_bucket_spec *spec, double value); + +/* Adds one observation. value is microseconds, bytes, or frames. */ +void dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, + apr_uint64_t value); + +#endif diff --git a/src/module.c b/src/module.c index b084348..4b3cc4a 100644 --- a/src/module.c +++ b/src/module.c @@ -18,6 +18,7 @@ #include "overlay_cache.h" #include "pipeline.h" #include "profile.h" +#include "metrics.h" #include "status.h" #include @@ -129,6 +130,11 @@ dims_init(apr_pool_t *p, apr_pool_t *plog, apr_pool_t* ptemp, server_rec *s) stats->download_timeout_count = 0; stats->imagemagick_timeout_count = 0; + status = dims_metrics_init(p, s); + if (status != APR_SUCCESS) { + return status; + } + return OK; } @@ -161,6 +167,8 @@ dims_child_init(apr_pool_t *p, server_rec *s) MagickWandGenesis(); + dims_metrics_child_init(); + dims_profiles_load(p, s, config->profile_dir); /* Every limit is per process, so the total a host can use is this From aabfd853f9a5e3f85c00178732fc16b4697b0ea4 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 09:07:07 -0400 Subject: [PATCH 02/16] Add the unit cases for the metrics block The bucket search, the histogram totals, and the four index maps. A bound belongs to its own bucket, and a value above the last bound belongs to +Inf. stub_httpd.c gains ap_mpm_query, which sizes the process slots. --- src/metrics.c | 2 + test/CMakeLists.txt | 2 + test/unit/main.c | 2 + test/unit/stub_httpd.c | 11 +++ test/unit/test_metrics.c | 161 +++++++++++++++++++++++++++++++++++++++ 5 files changed, 178 insertions(+) create mode 100644 test/unit/test_metrics.c diff --git a/src/metrics.c b/src/metrics.c index 0f1b4c7..9e6b99d 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -9,6 +9,8 @@ #include "module.h" #include + +#include #include dims_metrics_rec *dims_metrics; diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index aefdd11..8cc5644 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -103,6 +103,7 @@ add_executable(dims_unit_test unit/test_resize.c unit/test_rotate.c unit/test_encryption.c + unit/test_metrics.c unit/test_netguard.c unit/test_overlay_cache.c unit/test_param.c @@ -114,6 +115,7 @@ add_executable(dims_unit_test lib/golden.c lib/test.c ${CMAKE_SOURCE_DIR}/src/encryption.c + ${CMAKE_SOURCE_DIR}/src/metrics.c ${CMAKE_SOURCE_DIR}/src/netguard.c ${CMAKE_SOURCE_DIR}/src/overlay_cache.c ${CMAKE_SOURCE_DIR}/src/signature.c diff --git a/test/unit/main.c b/test/unit/main.c index 6fd6545..a9f23c6 100644 --- a/test/unit/main.c +++ b/test/unit/main.c @@ -21,6 +21,7 @@ extern const dims_test dims_tests_unit_adjustments[]; extern const dims_test dims_tests_unit_output[]; extern const dims_test dims_tests_unit_watermark[]; extern const dims_test dims_tests_unit_encryption[]; +extern const dims_test dims_tests_unit_metrics[]; extern const dims_test dims_tests_unit_netguard[]; extern const dims_test dims_tests_unit_overlay_cache[]; extern const dims_test dims_tests_unit_param[]; @@ -37,6 +38,7 @@ static const dims_test_group groups[] = { { "unit/test_output.c", dims_tests_unit_output }, { "unit/test_watermark.c", dims_tests_unit_watermark }, { "unit/test_encryption.c", dims_tests_unit_encryption }, + { "unit/test_metrics.c", dims_tests_unit_metrics }, { "unit/test_netguard.c", dims_tests_unit_netguard }, { "unit/test_overlay_cache.c", dims_tests_unit_overlay_cache }, { "unit/test_param.c", dims_tests_unit_param }, diff --git a/test/unit/stub_httpd.c b/test/unit/stub_httpd.c index 78facaa..d7e1641 100644 --- a/test/unit/stub_httpd.c +++ b/test/unit/stub_httpd.c @@ -144,3 +144,14 @@ dims_stub_fixture_dir(void) ? from_env : "/build/mod_dims/test/origin"; } + +/* + * The MPM daemon limit, which sizes the process slots in the metrics block. + * The in-process cases run no MPM, so report one slot. + */ +int +ap_mpm_query(int query_code, int *result) +{ + *result = 1; + return 0; +} diff --git a/test/unit/test_metrics.c b/test/unit/test_metrics.c new file mode 100644 index 0000000..787f68a --- /dev/null +++ b/test/unit/test_metrics.c @@ -0,0 +1,161 @@ +/* + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "../lib/test.h" +#include "../../src/metrics.h" + +#include + +/* + * A bound belongs to its own bucket, because Prometheus buckets are "less than + * or equal to". A value above the last bound belongs to +Inf, which sits at + * index bounds. + */ +static void +test_bucket_boundaries(void) +{ + const dims_bucket_spec *spec = &dims_duration_buckets; + + CHECK_INT(dims_metrics_bucket_index(spec, 0.0), 0, "zero"); + CHECK_INT(dims_metrics_bucket_index(spec, 0.005), 0, "the first bound"); + CHECK_INT(dims_metrics_bucket_index(spec, 0.0051), 1, "just above it"); + CHECK_INT(dims_metrics_bucket_index(spec, 10.0), spec->bounds - 1, + "the last bound"); + CHECK_INT(dims_metrics_bucket_index(spec, 10.1), spec->bounds, + "above the last bound"); +} + +static void +test_byte_and_frame_boundaries(void) +{ + CHECK_INT(dims_metrics_bucket_index(&dims_byte_buckets, 16384), 0, + "16Ki"); + CHECK_INT(dims_metrics_bucket_index(&dims_byte_buckets, 16385), 1, + "just above 16Ki"); + CHECK_INT(dims_metrics_bucket_index(&dims_byte_buckets, 1 << 30), + dims_byte_buckets.bounds, "a gigabyte"); + + CHECK_INT(dims_metrics_bucket_index(&dims_frame_buckets, 1), 0, + "one frame"); + CHECK_INT(dims_metrics_bucket_index(&dims_frame_buckets, 3), 2, + "three frames"); + CHECK_INT(dims_metrics_bucket_index(&dims_frame_buckets, 500), + dims_frame_buckets.bounds, "five hundred frames"); +} + +/* Every bucket table fits the record, which the exposition writer walks. */ +static void +test_bucket_tables_fit(void) +{ + CHECK(dims_duration_buckets.bounds + 1 <= DIMS_BUCKET_MAX, + "the duration table fits"); + CHECK(dims_byte_buckets.bounds + 1 <= DIMS_BUCKET_MAX, + "the byte table fits"); + CHECK(dims_frame_buckets.bounds + 1 <= DIMS_BUCKET_MAX, + "the frame table fits"); +} + +/* + * A bucket holds the observations that fall in it alone. The writer adds them + * up, so the total across the table equals the count. + */ +static void +test_histogram_totals(void) +{ + dims_histogram_rec h; + apr_uint64_t total = 0; + int i; + + memset(&h, 0, sizeof(h)); + + /* Three microseconds, half a second, and a minute. */ + dims_metrics_observe(&h, &dims_duration_buckets, 3); + dims_metrics_observe(&h, &dims_duration_buckets, 500000); + dims_metrics_observe(&h, &dims_duration_buckets, 60000000); + + CHECK_INT((long) h.count, 3, "the count"); + CHECK_INT((long) h.sum, 60500003, "the sum in microseconds"); + + for (i = 0; i < DIMS_BUCKET_MAX; i++) { + total += h.bucket[i]; + } + + CHECK_INT((long) total, 3, "the buckets add up to the count"); + CHECK_INT((long) h.bucket[0], 1, "three microseconds is the first bucket"); + CHECK_INT((long) h.bucket[dims_duration_buckets.bounds], 1, + "a minute is the +Inf bucket"); +} + +/* A byte observation reports bytes, with no division. */ +static void +test_histogram_counts_bytes(void) +{ + dims_histogram_rec h; + + memset(&h, 0, sizeof(h)); + + dims_metrics_observe(&h, &dims_byte_buckets, 2048); + + CHECK_INT((long) h.sum, 2048, "the sum in bytes"); + CHECK_INT((long) h.bucket[0], 1, "two kilobytes is the first bucket"); +} + +static void +test_outcome_index(void) +{ + CHECK_INT(dims_metrics_outcome_index(DIMS_SUCCESS), 0, "success"); + CHECK_INT(dims_metrics_outcome_index(DIMS_NETWORK_REFUSED), + DIMS_OUTCOME_COUNT - 1, "the last status"); + CHECK_INT(dims_metrics_outcome_index(DIMS_IGNORE), DIMS_OUTCOME_COUNT - 1, + "a status outside the table"); + CHECK_STR(dims_metrics_outcome_name(0), "success", "the first name"); +} + +static void +test_code_index(void) +{ + CHECK_STR(dims_metrics_code_name(dims_metrics_code_index(200)), "200", + "a listed code"); + CHECK_STR(dims_metrics_code_name(dims_metrics_code_index(504)), "504", + "the last listed code"); + CHECK_STR(dims_metrics_code_name(dims_metrics_code_index(418)), "other", + "a code outside the list"); +} + +/* DimsOriginStatusMode forward reports whatever the origin returned. */ +static void +test_origin_code_index(void) +{ + CHECK_STR(dims_metrics_origin_code_name(dims_metrics_origin_code_index(304)), + "304", "a listed code"); + CHECK_STR(dims_metrics_origin_code_name(dims_metrics_origin_code_index(451)), + "other", "a code outside the list"); +} + +static void +test_format_index(void) +{ + CHECK_STR(dims_metrics_format_name(dims_metrics_format_index("PNG")), + "png", "an upper case format"); + CHECK_STR(dims_metrics_format_name(dims_metrics_format_index("JPG")), + "jpeg", "JPG names JPEG"); + CHECK_STR(dims_metrics_format_name(dims_metrics_format_index("PCX")), + "other", "a format outside the list"); + CHECK_STR(dims_metrics_format_name(dims_metrics_format_index(NULL)), + "other", "no format"); +} + +const dims_test dims_tests_unit_metrics[] = { + { "TestBucketBoundaries", test_bucket_boundaries, NULL }, + { "TestByteAndFrameBoundaries", test_byte_and_frame_boundaries, NULL }, + { "TestBucketTablesFit", test_bucket_tables_fit, NULL }, + { "TestHistogramTotals", test_histogram_totals, NULL }, + { "TestHistogramCountsBytes", test_histogram_counts_bytes, NULL }, + { "TestOutcomeIndex", test_outcome_index, NULL }, + { "TestCodeIndex", test_code_index, NULL }, + { "TestOriginCodeIndex", test_origin_code_index, NULL }, + { "TestFormatIndex", test_format_index, NULL }, + DIMS_TEST_END +}; From fc194d8a0887cd42b7f0b681d840fb7e89efb49c Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 09:13:42 -0400 Subject: [PATCH 03/16] Serve the metrics endpoint DimsMetricsEnabled is the switch and defaults to off. A location that sets the dims-metrics handler serves Prometheus text 0.0.4 when the directive is on, and httpd returns 404 when it is off. The writer prints a family per counter and per histogram, with cumulative _bucket lines, a _sum, and a _count. Every value is zero until the next commits record them. A bucket bound goes through snprintf. The httpd formatter prints .005 for 0.005 and rounds 1048576 to 1048580, and a dashboard matches le as a string. src/metrics_report.c holds the writer, so the in-process cases link the block and the index maps without the httpd response API. --- CMakeLists.txt | 1 + src/configuration.c | 17 ++++ src/handler.c | 3 + src/metrics.c | 1 + src/metrics.h | 3 + src/metrics_report.c | 200 +++++++++++++++++++++++++++++++++++++++ src/mod_dims.h | 3 + test/CMakeLists.txt | 3 + test/conf/dims-test.conf | 23 +++++ test/http/main.c | 2 + test/http/test_metrics.c | 173 +++++++++++++++++++++++++++++++++ test/lib/prometheus.c | 77 +++++++++++++++ test/lib/prometheus.h | 26 +++++ 13 files changed, 532 insertions(+) create mode 100644 src/metrics_report.c create mode 100644 test/http/test_metrics.c create mode 100644 test/lib/prometheus.c create mode 100644 test/lib/prometheus.h diff --git a/CMakeLists.txt b/CMakeLists.txt index 4ba6734..902d167 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -83,6 +83,7 @@ add_library(mod_dims MODULE src/svgguard.c src/url.c src/metrics.c + src/metrics_report.c src/status.c src/mod_dims.c src/module.c diff --git a/src/configuration.c b/src/configuration.c index 095a547..7e779cb 100644 --- a/src/configuration.c +++ b/src/configuration.c @@ -54,6 +54,10 @@ dims_create_config(apr_pool_t *p, server_rec *s) config->origin_status_mode = DIMS_ORIGIN_STATUS_FORWARD; config->status_verbose = 1; + /* Off, so a server that upgrades publishes no metrics until an operator + * turns it on. */ + config->metrics_enabled = 0; + /* The cache holds fetched overlays, and an evicted one is fetched again, * so a bound costs a caller nothing. */ config->overlay_cache_max_entries = 1024; @@ -352,6 +356,15 @@ dims_config_set_allow_private_addresses(cmd_parms *cmd, void *dummy, int arg) return NULL; } +static const char * +dims_config_set_metrics_enabled(cmd_parms *cmd, void *dummy, int arg) +{ + dims_config_rec *config = (dims_config_rec *) ap_get_module_config( + cmd->server->module_config, &dims_module); + config->metrics_enabled = arg; + return NULL; +} + static const char * dims_config_set_allowlist_signed(cmd_parms *cmd, void *dummy, const char *arg) { @@ -625,6 +638,10 @@ const command_rec dims_directives[] = "to report the status the origin returned, or map to report " "404 for a missing source, 504 for a timeout, and 502 for " "every other origin failure. The default is forward."), + AP_INIT_FLAG("DimsMetricsEnabled", + dims_config_set_metrics_enabled, NULL, RSRC_CONF, + "Whether the module serves metrics at a location that sets " + "the dims-metrics handler. The default is Off."), AP_INIT_FLAG("DimsStatusVerbose", dims_config_set_status_verbose, NULL, RSRC_CONF, "Whether the status handler prints the mod_dims, ImageMagick, " diff --git a/src/handler.c b/src/handler.c index 0e34cbb..dcb8d7c 100644 --- a/src/handler.c +++ b/src/handler.c @@ -13,6 +13,7 @@ #include "url.h" #include "dims5.h" #include "encryption.h" +#include "metrics.h" #include "status.h" #include "pipeline.h" @@ -547,6 +548,8 @@ dims_handler(request_rec *r) d->scheme = DIMS_SCHEME_DIMS5; return dims_handle_request(d); + } else if(strcmp(r->handler, "dims-metrics") == 0) { + return dims_metrics_handler(r); } else if(strcmp(r->handler, "dims-status") == 0) { return dims_status_handler(r); } else if(strcmp(r->handler, "dims-sizer") == 0) { diff --git a/src/metrics.c b/src/metrics.c index 9e6b99d..6992745 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -295,3 +295,4 @@ dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, apr_atomic_add64(&h->sum, value); apr_atomic_inc64(&h->count); } + diff --git a/src/metrics.h b/src/metrics.h index 12b0b4a..9bbefb9 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -119,4 +119,7 @@ int dims_metrics_bucket_index(const dims_bucket_spec *spec, double value); void dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, apr_uint64_t value); +/* Answers a location that sets the dims-metrics handler. */ +apr_status_t dims_metrics_handler(request_rec *r); + #endif diff --git a/src/metrics_report.c b/src/metrics_report.c new file mode 100644 index 0000000..eb51e3a --- /dev/null +++ b/src/metrics_report.c @@ -0,0 +1,200 @@ +/* + * The metrics endpoint. + * + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "metrics.h" +#include "module.h" + +#include + +/* + * The exposition writer. + * + * Prometheus text 0.0.4. A family prints a # HELP line, a # TYPE line, and one + * line per series. A histogram prints a cumulative _bucket line per bound, + * then _sum and _count. + */ + +static apr_uint64_t +read64(const apr_uint64_t *value) +{ + return apr_atomic_read64((apr_uint64_t *) value); +} + +static void +head(request_rec *r, const char *name, const char *help, const char *type) +{ + ap_rprintf(r, "# HELP %s %s\n# TYPE %s %s\n", name, help, name, type); +} + +/* + * labels is the label set without braces, such as endpoint="dims3". Pass an + * empty string for a family with no labels. + */ +static void +histogram(request_rec *r, const char *name, const dims_histogram_rec *h, + const dims_bucket_spec *spec, int seconds, const char *labels) +{ + apr_uint64_t running = 0; + char braced[96]; + char bound[32]; + int i; + + for (i = 0; i < spec->bounds; i++) { + running += read64(&h->bucket[i]); + /* snprintf, because the httpd formatter prints .005 for 0.005 and + * rounds 1048576 to 1048580. A dashboard matches le as a string. */ + snprintf(bound, sizeof(bound), "%.15g", spec->bound[i]); + ap_rprintf(r, "%s_bucket{%s%sle=\"%s\"} %" APR_UINT64_T_FMT "\n", + name, labels, labels[0] ? "," : "", bound, running); + } + + running += read64(&h->bucket[spec->bounds]); + ap_rprintf(r, "%s_bucket{%s%sle=\"+Inf\"} %" APR_UINT64_T_FMT "\n", + name, labels, labels[0] ? "," : "", running); + + /* A family with no labels prints no braces. */ + if (labels[0] != '\0') { + apr_snprintf(braced, sizeof(braced), "{%s}", labels); + } else { + braced[0] = '\0'; + } + + if (seconds) { + ap_rprintf(r, "%s_sum%s %.6f\n", name, braced, + (double) read64(&h->sum) / 1000000.0); + } else { + ap_rprintf(r, "%s_sum%s %" APR_UINT64_T_FMT "\n", name, braced, + read64(&h->sum)); + } + + ap_rprintf(r, "%s_count%s %" APR_UINT64_T_FMT "\n", name, braced, + read64(&h->count)); +} + +static void +write_metrics(request_rec *r) +{ + dims_metrics_rec *m = dims_metrics; + char labels[64]; + int e, i; + + head(r, "dims_requests_total", "Requests by endpoint and outcome.", + "counter"); + for (e = 0; e < DIMS_ENDPOINT_COUNT; e++) { + for (i = 0; i < DIMS_OUTCOME_COUNT; i++) { + ap_rprintf(r, "dims_requests_total{endpoint=\"%s\",outcome=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_endpoint_name(e), dims_metrics_outcome_name(i), + read64(&m->requests[e][i])); + } + } + + head(r, "dims_responses_total", "Responses by endpoint and status code.", + "counter"); + for (e = 0; e < DIMS_ENDPOINT_COUNT; e++) { + for (i = 0; i < DIMS_CODE_COUNT; i++) { + ap_rprintf(r, "dims_responses_total{endpoint=\"%s\",code=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_endpoint_name(e), dims_metrics_code_name(i), + read64(&m->responses[e][i])); + } + } + + head(r, "dims_requests_in_flight", "Requests being served.", "gauge"); + for (e = 0; e < DIMS_ENDPOINT_COUNT; e++) { + ap_rprintf(r, "dims_requests_in_flight{endpoint=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_endpoint_name(e), read64(&m->in_flight[e])); + } + + head(r, "dims_origin_responses_total", + "Source fetches by the status the origin returned.", "counter"); + for (i = 0; i < DIMS_ORIGIN_CODE_COUNT; i++) { + ap_rprintf(r, "dims_origin_responses_total{code=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_origin_code_name(i), + read64(&m->origin_responses[i])); + } + + head(r, "dims_source_format_total", "Source images by format.", "counter"); + for (i = 0; i < DIMS_FORMAT_COUNT; i++) { + ap_rprintf(r, "dims_source_format_total{format=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_format_name(i), read64(&m->source_format[i])); + } + + head(r, "dims_output_format_total", "Responses by image format.", "counter"); + for (i = 0; i < DIMS_FORMAT_COUNT; i++) { + ap_rprintf(r, "dims_output_format_total{format=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_format_name(i), read64(&m->output_format[i])); + } + + head(r, "dims_source_bytes_total", "Bytes fetched from an origin.", + "counter"); + ap_rprintf(r, "dims_source_bytes_total %" APR_UINT64_T_FMT "\n", + read64(&m->source_bytes_total)); + + head(r, "dims_output_bytes_total", "Bytes written to callers.", "counter"); + ap_rprintf(r, "dims_output_bytes_total %" APR_UINT64_T_FMT "\n", + read64(&m->output_bytes_total)); + + head(r, "dims_request_duration_seconds", "Time to serve a request.", + "histogram"); + for (e = 0; e < DIMS_ENDPOINT_COUNT; e++) { + apr_snprintf(labels, sizeof(labels), "endpoint=\"%s\"", + dims_metrics_endpoint_name(e)); + histogram(r, "dims_request_duration_seconds", &m->request_duration[e], + &dims_duration_buckets, 1, labels); + } + + head(r, "dims_source_fetch_duration_seconds", + "Time to fetch a source image.", "histogram"); + histogram(r, "dims_source_fetch_duration_seconds", &m->download_duration, + &dims_duration_buckets, 1, ""); + + head(r, "dims_imagemagick_duration_seconds", "Time inside ImageMagick.", + "histogram"); + histogram(r, "dims_imagemagick_duration_seconds", &m->imagemagick_duration, + &dims_duration_buckets, 1, ""); + + head(r, "dims_source_bytes", "Source image size.", "histogram"); + histogram(r, "dims_source_bytes", &m->source_bytes, &dims_byte_buckets, 0, + ""); + + head(r, "dims_output_bytes", "Response image size.", "histogram"); + histogram(r, "dims_output_bytes", &m->output_bytes, &dims_byte_buckets, 0, + ""); + + head(r, "dims_source_frames", "Frames in a source image.", "histogram"); + histogram(r, "dims_source_frames", &m->source_frames, &dims_frame_buckets, + 0, ""); +} + +apr_status_t +dims_metrics_handler(request_rec *r) +{ + dims_config_rec *config = (dims_config_rec *) ap_get_module_config( + r->server->module_config, &dims_module); + + if (config == NULL || !config->metrics_enabled || dims_metrics == NULL) { + return DECLINED; + } + + if (r->method_number != M_GET) { + return HTTP_METHOD_NOT_ALLOWED; + } + + ap_set_content_type(r, "text/plain; version=0.0.4; charset=utf-8"); + + if (!r->header_only) { + write_metrics(r); + ap_rflush(r); + } + + return OK; +} diff --git a/src/mod_dims.h b/src/mod_dims.h index d5651ac..2a1d627 100644 --- a/src/mod_dims.h +++ b/src/mod_dims.h @@ -182,6 +182,9 @@ struct dims_config_rec { * DimsStatusVerbose. */ int status_verbose; + /* Whether the module serves /metrics. Set from DimsMetricsEnabled. */ + int metrics_enabled; + /* Bounds on the overlay cache. Zero turns either off. Set from * DimsOverlayCacheMaxEntries and DimsOverlayCacheMaxAge. */ int overlay_cache_max_entries; diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index 8cc5644..fe6f9d7 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -22,6 +22,7 @@ add_executable(dims_test http/test_signing.c http/test_sources.c http/test_legacy_endpoints.c + http/test_metrics.c http/test_no_error_image.c http/test_source_limit.c http/test_status.c @@ -30,6 +31,7 @@ add_executable(dims_test http/test_watermark.c lib/common.c lib/golden.c + lib/prometheus.c lib/imagesize.c lib/request.c lib/signing.c @@ -113,6 +115,7 @@ add_executable(dims_unit_test unit/test_thumbnail.c unit/test_watermark.c lib/golden.c + lib/prometheus.c lib/test.c ${CMAKE_SOURCE_DIR}/src/encryption.c ${CMAKE_SOURCE_DIR}/src/metrics.c diff --git a/test/conf/dims-test.conf b/test/conf/dims-test.conf index b2af420..f4bc70c 100644 --- a/test/conf/dims-test.conf +++ b/test/conf/dims-test.conf @@ -39,6 +39,14 @@ DimsAddWhitelist origin SetHandler dims-status +# The metrics endpoint. The directive is the switch and the location names the +# path, so a case can turn it off by leaving the directive at its default. +DimsMetricsEnabled on + + + SetHandler dims-metrics + + # A location the server denies. A /dims3/ request that names a local file here # must not read it: the module honors the access check the subrequest runs. @@ -252,3 +260,18 @@ Listen 8008 SetHandler None + +Listen 8009 + +# A server that sets the metrics handler and turns the directive off, so the +# endpoint returns 404. A virtual host inherits the main server directives, so +# this one names it. + + ServerName metricsoff + + DimsMetricsEnabled off + + + SetHandler dims-metrics + + diff --git a/test/http/main.c b/test/http/main.c index 69b04d0..bc3800c 100644 --- a/test/http/main.c +++ b/test/http/main.c @@ -27,6 +27,7 @@ extern const dims_test dims_tests_cache_headers[]; extern const dims_test dims_tests_errors[]; extern const dims_test dims_tests_status[]; extern const dims_test dims_tests_legacy_endpoints[]; +extern const dims_test dims_tests_metrics[]; extern const dims_test dims_tests_no_error_image[]; extern const dims_test dims_tests_source_limit[]; extern const dims_test dims_tests_origin_status[]; @@ -48,6 +49,7 @@ static const dims_test_group groups[] = { { "test_errors.c", dims_tests_errors }, { "test_status.c", dims_tests_status }, { "test_legacy_endpoints.c", dims_tests_legacy_endpoints }, + { "test_metrics.c", dims_tests_metrics }, { "test_no_error_image.c", dims_tests_no_error_image }, { "test_source_limit.c", dims_tests_source_limit }, { "test_origin_status.c", dims_tests_origin_status }, diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c new file mode 100644 index 0000000..37aa73f --- /dev/null +++ b/test/http/test_metrics.c @@ -0,0 +1,173 @@ +/* + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "../lib/common.h" +#include "../lib/prometheus.h" + +/* The server that sets the handler and turns DimsMetricsEnabled off. */ +static const char * +metrics_off_url(void) +{ + const char *from_env = getenv("DIMS_TEST_METRICS_OFF_URL"); + return (from_env != NULL && from_env[0] != '\0') ? from_env + : "http://dims:8009"; +} + +static dims_response * +scrape(void) +{ + char url[512]; + + snprintf(url, sizeof(url), "%s/metrics", dims_base_url()); + + return dims_get_absolute(url); +} + +static void +test_metrics_content_type(void) +{ + dims_response *response = scrape(); + const char *type; + + CHECK_INT(response->status, 200, "the metrics endpoint"); + + type = dims_header_value(response, "Content-Type"); + CHECK(type != NULL && strstr(type, "text/plain") != NULL && + strstr(type, "version=0.0.4") != NULL, + "the Prometheus content type, got %s", type ? type : "none"); + + dims_response_free(response); +} + +/* + * Every line is a comment or a sample. A sample is a name, an optional label + * set in braces, a space, and a value. + */ +static void +test_metrics_format(void) +{ + dims_response *response = scrape(); + char *body; + char *line; + char *state = NULL; + int samples = 0; + + body = malloc(response->body_len + 1); + if (body == NULL) { + FAIL("out of memory"); + dims_response_free(response); + return; + } + + memcpy(body, response->body, response->body_len); + body[response->body_len] = '\0'; + + for (line = strtok_r(body, "\n", &state); line != NULL; + line = strtok_r(NULL, "\n", &state)) { + if (strncmp(line, "# HELP ", 7) == 0 || + strncmp(line, "# TYPE ", 7) == 0) { + continue; + } + + if (strchr(line, ' ') == NULL) { + FAIL("a line with no value: %s", line); + break; + } + + samples++; + } + + CHECK(samples > 50, "the page reports samples, got %d", samples); + + free(body); + dims_response_free(response); +} + +/* A histogram reports a bucket per bound, a +Inf bucket, a sum, and a count. */ +static void +test_metrics_histograms(void) +{ + dims_response *response = scrape(); + + CHECK(dims_prom_contains(response, + "dims_request_duration_seconds_bucket{endpoint=\"dims4\"," + "le=\"+Inf\"}"), + "the request duration +Inf bucket"); + CHECK(dims_prom_contains(response, "dims_request_duration_seconds_sum{"), + "the request duration sum"); + CHECK(dims_prom_contains(response, "dims_request_duration_seconds_count{"), + "the request duration count"); + CHECK(dims_prom_contains(response, "dims_source_bytes_bucket{le=\"16384\"}"), + "a byte bucket"); + + /* A bound prints exactly. Six significant digits round 1048576 to + * 1048580, which names a bucket no dashboard expects. */ + CHECK(dims_prom_contains(response, + "dims_source_bytes_bucket{le=\"1048576\"}"), + "the one megabyte bound"); + CHECK(dims_prom_contains(response, + "dims_source_bytes_bucket{le=\"67108864\"}"), + "the sixty four megabyte bound"); + CHECK(dims_prom_contains(response, "dims_request_duration_seconds_bucket{" + "endpoint=\"dims5\",le=\"0.005\"}"), + "the five millisecond bound"); + + /* A family with no labels prints no braces. */ + CHECK(!dims_prom_contains(response, "_count{} "), + "no empty label set"); + + dims_response_free(response); +} + +/* Every family the block holds appears, whatever its value. */ +static void +test_metrics_families(void) +{ + dims_response *response = scrape(); + static const char *const names[] = { + "# TYPE dims_requests_total counter", + "# TYPE dims_responses_total counter", + "# TYPE dims_requests_in_flight gauge", + "# TYPE dims_origin_responses_total counter", + "# TYPE dims_source_format_total counter", + "# TYPE dims_output_format_total counter", + "# TYPE dims_source_bytes_total counter", + "# TYPE dims_output_bytes_total counter", + "# TYPE dims_imagemagick_duration_seconds histogram", + "# TYPE dims_source_frames histogram", + NULL + }; + int i; + + for (i = 0; names[i] != NULL; i++) { + CHECK(dims_prom_contains(response, names[i]), "%s", names[i]); + } + + dims_response_free(response); +} + +/* The directive is the switch. Off, the handler reports no metrics. */ +static void +test_metrics_disabled(void) +{ + char url[512]; + dims_response *response; + + snprintf(url, sizeof(url), "%s/metrics", metrics_off_url()); + response = dims_get_absolute(url); + + CHECK_INT(response->status, 404, "DimsMetricsEnabled off"); + + dims_response_free(response); +} + +const dims_test dims_tests_metrics[] = { + { "TestMetricsContentType", test_metrics_content_type, NULL }, + { "TestMetricsFormat", test_metrics_format, NULL }, + { "TestMetricsHistograms", test_metrics_histograms, NULL }, + { "TestMetricsFamilies", test_metrics_families, NULL }, + { "TestMetricsDisabled", test_metrics_disabled, NULL }, + DIMS_TEST_END +}; diff --git a/test/lib/prometheus.c b/test/lib/prometheus.c new file mode 100644 index 0000000..e23caa2 --- /dev/null +++ b/test/lib/prometheus.c @@ -0,0 +1,77 @@ +/* + * Reading a Prometheus exposition body in a case. + * + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#include "prometheus.h" + +#include +#include + +/* The body with a terminator on the end. The caller frees it. */ +static char * +body_string(const dims_response *response) +{ + char *copy; + + if (response == NULL || response->body == NULL) { + return NULL; + } + + copy = malloc(response->body_len + 1); + if (copy == NULL) { + return NULL; + } + + memcpy(copy, response->body, response->body_len); + copy[response->body_len] = '\0'; + + return copy; +} + +int +dims_prom_contains(const dims_response *response, const char *text) +{ + char *body = body_string(response); + int found; + + if (body == NULL) { + return 0; + } + + found = strstr(body, text) != NULL; + free(body); + + return found; +} + +double +dims_prom_value(const dims_response *response, const char *prefix) +{ + char *body = body_string(response); + size_t len = strlen(prefix); + char *line; + char *state = NULL; + double value = -1; + + if (body == NULL) { + return -1; + } + + for (line = strtok_r(body, "\n", &state); line != NULL; + line = strtok_r(NULL, "\n", &state)) { + /* A sample is the name, its labels, a space, and the value. Comparing + * the space as well keeps dims_requests_total apart from + * dims_requests_total_something. */ + if (strncmp(line, prefix, len) == 0 && line[len] == ' ') { + value = strtod(line + len + 1, NULL); + break; + } + } + + free(body); + + return value; +} diff --git a/test/lib/prometheus.h b/test/lib/prometheus.h new file mode 100644 index 0000000..1a955ab --- /dev/null +++ b/test/lib/prometheus.h @@ -0,0 +1,26 @@ +/* + * Reading a Prometheus exposition body in a case. + * + * Copyright 2026 Jeremy Collins + * SPDX-License-Identifier: Apache-2.0 + */ + +#ifndef DIMS_TEST_PROMETHEUS_H +#define DIMS_TEST_PROMETHEUS_H + +#include "request.h" + +/* Whether the body holds the text. The body needs no terminator. */ +int dims_prom_contains(const dims_response *response, const char *text); + +/* + * The value of the sample whose line starts with prefix, which is a metric + * name and its label set: + * + * dims_requests_total{endpoint="dims4",outcome="success"} + * + * Returns -1 when no line starts with it. + */ +double dims_prom_value(const dims_response *response, const char *prefix); + +#endif From a5dc6828256d477deffeb0fdd39ffadb0bc9d6b8 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 09:40:36 -0400 Subject: [PATCH 04/16] Record the request outcome and duration dims_requests_total, dims_responses_total, dims_request_duration_seconds, and dims_requests_in_flight. dims_handler sets d->endpoint and calls dims_metrics_request_begin, which increments the gauge and registers a pool cleanup. The cleanup decrements the gauge and records the outcome, the response code, and the duration, so every return path in the handler records exactly once. --- src/handler.c | 7 ++++ src/metrics.c | 44 +++++++++++++++++++++++ src/metrics.h | 6 ++++ src/mod_dims.h | 3 ++ test/http/test_metrics.c | 77 ++++++++++++++++++++++++++++++++++++++++ 5 files changed, 137 insertions(+) diff --git a/src/handler.c b/src/handler.c index dcb8d7c..cd4b183 100644 --- a/src/handler.c +++ b/src/handler.c @@ -391,6 +391,8 @@ dims_handler(request_rec *r) /* Handle local filesystem images w/DIMS parameters. */ d->filename = r->canonical_filename; d->unparsed_commands = r->path_info; + d->endpoint = DIMS_ENDPOINT_LOCAL; + dims_metrics_request_begin(d); return dims_handle_request(d); } else if ((strcmp(r->handler, "dims3") == 0) || @@ -399,6 +401,9 @@ dims_handler(request_rec *r) char *p, *fixed_url = NULL, *commands = NULL, *eurl = NULL; int is_dims4 = strcmp(r->handler, "dims4") == 0; + d->endpoint = is_dims4 ? DIMS_ENDPOINT_DIMS4 : DIMS_ENDPOINT_DIMS3; + dims_metrics_request_begin(d); + if (is_dims4) { d->use_secret_key = 1; } @@ -546,6 +551,8 @@ dims_handler(request_rec *r) return dims_handle_request(d); } else if(strcmp(r->handler, "dims5") == 0) { d->scheme = DIMS_SCHEME_DIMS5; + d->endpoint = DIMS_ENDPOINT_DIMS5; + dims_metrics_request_begin(d); return dims_handle_request(d); } else if(strcmp(r->handler, "dims-metrics") == 0) { diff --git a/src/metrics.c b/src/metrics.c index 6992745..16b5445 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -296,3 +296,47 @@ dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, apr_atomic_inc64(&h->count); } + +/* + * The end of a request, reached through a pool cleanup so that every return + * path in the handler records exactly once. + */ +static apr_status_t +record_request(void *baton) +{ + dims_request_rec *d = (dims_request_rec *) baton; + dims_metrics_rec *m = dims_metrics; + int endpoint = d->endpoint; + apr_uint64_t micros; + + if (m == NULL || endpoint < 0 || endpoint >= DIMS_ENDPOINT_COUNT) { + return APR_SUCCESS; + } + + apr_atomic_dec64(&m->in_flight[endpoint]); + + apr_atomic_inc64(&m->requests[endpoint] + [dims_metrics_outcome_index(d->status)]); + apr_atomic_inc64(&m->responses[endpoint] + [dims_metrics_code_index(d->r->status)]); + + micros = (apr_uint64_t) (apr_time_now() - d->start_time); + dims_metrics_observe(&m->request_duration[endpoint], &dims_duration_buckets, + micros); + + return APR_SUCCESS; +} + +void +dims_metrics_request_begin(dims_request_rec *d) +{ + if (dims_metrics == NULL || d->endpoint < 0 || + d->endpoint >= DIMS_ENDPOINT_COUNT) { + return; + } + + apr_atomic_inc64(&dims_metrics->in_flight[d->endpoint]); + + apr_pool_cleanup_register(d->r->pool, d, record_request, + apr_pool_cleanup_null); +} diff --git a/src/metrics.h b/src/metrics.h index 9bbefb9..155e6ac 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -119,6 +119,12 @@ int dims_metrics_bucket_index(const dims_bucket_spec *spec, double value); void dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, apr_uint64_t value); +/* + * Counts a request and records its duration when it ends. Registers a pool + * cleanup, so every return path in the handler reaches it exactly once. + */ +void dims_metrics_request_begin(dims_request_rec *d); + /* Answers a location that sets the dims-metrics handler. */ apr_status_t dims_metrics_handler(request_rec *r); diff --git a/src/mod_dims.h b/src/mod_dims.h index 2a1d627..d5b89c9 100644 --- a/src/mod_dims.h +++ b/src/mod_dims.h @@ -237,6 +237,9 @@ struct dims_request_rec { char *image_url; int use_no_image; + /* Which endpoint served this, as a dims_endpoint_t. */ + int endpoint; + /* The URL to the NOIMAGE image in case of failures. */ char *no_image_url; diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index 37aa73f..1ae5d76 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -163,11 +163,88 @@ test_metrics_disabled(void) dims_response_free(response); } +/* + * A request moves its counter. The value is read before and after, because + * other cases in the run share the server and its counters. + */ +static void +test_metrics_counts_a_success(void) +{ + dims_response *before = scrape(); + double was = dims_prom_value(before, + "dims_requests_total{endpoint=\"dims4\",outcome=\"success\"}"); + dims_response *image; + dims_response *after; + + image = dims_request_ops("resize/40x40", "grid.png"); + CHECK_INT(image->status, 200, "the image request"); + dims_response_free(image); + + after = scrape(); + CHECK(dims_prom_value(after, + "dims_requests_total{endpoint=\"dims4\",outcome=\"success\"}") + >= was + 1, + "the success counter moved from %g", was); + CHECK(dims_prom_value(after, + "dims_responses_total{endpoint=\"dims4\",code=\"200\"}") + >= 1, + "the 200 counter"); + + dims_response_free(before); + dims_response_free(after); +} + +/* + * A host outside the allowlist reports its own outcome on /dims3/, which is + * the endpoint that enforces the list. + */ +static void +test_metrics_counts_a_refusal(void) +{ + dims_response *before = scrape(); + double was = dims_prom_value(before, "dims_requests_total{endpoint=\"dims3\"," + "outcome=\"hostname_not_in_whitelist\"}"); + dims_response *refused; + dims_response *after; + + refused = dims_get("/dims3/TEST/resize/40x40/" + "?url=http://notallowed:8080/grid.png"); + dims_response_free(refused); + + after = scrape(); + CHECK(dims_prom_value(after, "dims_requests_total{endpoint=\"dims3\"," + "outcome=\"hostname_not_in_whitelist\"}") >= was + 1, + "the refusal counter moved from %g", was); + CHECK(dims_prom_value(after, + "dims_request_duration_seconds_count{endpoint=\"dims3\"}") + >= 1, + "the duration histogram counted it"); + + dims_response_free(before); + dims_response_free(after); +} + +/* Nothing is in flight while the scrape runs, because the scrape is not. */ +static void +test_metrics_in_flight_settles(void) +{ + dims_response *response = scrape(); + + CHECK_INT((long) dims_prom_value(response, + "dims_requests_in_flight{endpoint=\"dims4\"}"), + 0, "in flight after the request ended"); + + dims_response_free(response); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, { "TestMetricsHistograms", test_metrics_histograms, NULL }, { "TestMetricsFamilies", test_metrics_families, NULL }, + { "TestMetricsCountsASuccess", test_metrics_counts_a_success, NULL }, + { "TestMetricsCountsARefusal", test_metrics_counts_a_refusal, NULL }, + { "TestMetricsInFlightSettles", test_metrics_in_flight_settles, NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From 6f7462adaeeecf71e7c0777433eb579ed159551e Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 09:44:27 -0400 Subject: [PATCH 05/16] Record the source download dims_source_fetch_duration_seconds, dims_source_bytes, dims_source_bytes_total, dims_origin_responses_total, and dims_source_format_total. The request record already holds the duration, the size, and the origin status, so the same pool cleanup records them. dims_fetch_remote_image keeps the format the wand read as a metrics slot, because the string belongs to ImageMagick. download_time counts milliseconds, so a fetch inside one millisecond reports zero. It belongs in the first bucket rather than nowhere. --- src/handler.c | 3 +++ src/metrics.c | 27 +++++++++++++++++++++++++++ src/mod_dims.c | 11 +++++++++++ src/mod_dims.h | 4 ++++ test/http/test_metrics.c | 30 ++++++++++++++++++++++++++++++ 5 files changed, 75 insertions(+) diff --git a/src/handler.c b/src/handler.c index cd4b183..6942d39 100644 --- a/src/handler.c +++ b/src/handler.c @@ -358,6 +358,9 @@ dims_handler(request_rec *r) d->client_config = NULL; d->no_image_url = d->config->no_image_url; d->use_no_image = 0; + d->endpoint = -1; + d->source_format_index = -1; + d->output_format_index = -1; d->image_url = NULL; d->filename = NULL; d->cache_control = NULL; diff --git a/src/metrics.c b/src/metrics.c index 16b5445..cc3995e 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -324,6 +324,33 @@ record_request(void *baton) dims_metrics_observe(&m->request_duration[endpoint], &dims_duration_buckets, micros); + /* + * The source, when the request reached one. fetch_http_status names a + * source fetch, and download_time alone names an error image fetch. + * download_time counts milliseconds, so a fetch inside one millisecond + * reports zero and belongs in the first bucket. + */ + if (d->fetch_http_status != 0 || d->download_time > 0) { + dims_metrics_observe(&m->download_duration, &dims_duration_buckets, + (apr_uint64_t) d->download_time * 1000); + } + + if (d->original_image_size > 0) { + apr_atomic_add64(&m->source_bytes_total, + (apr_uint64_t) d->original_image_size); + dims_metrics_observe(&m->source_bytes, &dims_byte_buckets, + (apr_uint64_t) d->original_image_size); + } + + if (d->fetch_http_status != 0) { + apr_atomic_inc64(&m->origin_responses[ + dims_metrics_origin_code_index(d->fetch_http_status)]); + } + + if (d->source_format_index >= 0) { + apr_atomic_inc64(&m->source_format[d->source_format_index]); + } + return APR_SUCCESS; } diff --git a/src/mod_dims.c b/src/mod_dims.c index 8ba090d..9d465d5 100644 --- a/src/mod_dims.c +++ b/src/mod_dims.c @@ -29,6 +29,7 @@ #include "mod_dims.h" #include "curl.h" #include "netguard.h" +#include "metrics.h" #include "status.h" #include "pipeline.h" #include "svgguard.h" @@ -316,6 +317,16 @@ dims_fetch_remote_image(dims_request_rec *d, const char *url) } d->imagemagick_time += (apr_time_now() - start_time) / 1000; + /* The format the wand read, kept as a metrics slot because the string + * belongs to ImageMagick. The error image reports its own format, so + * only a source fetch records one. */ + if (url != NULL) { + char *source_format = MagickGetImageFormat(d->wand); + + d->source_format_index = dims_metrics_format_index(source_format); + MagickRelinquishMemory(source_format); + } + if(d->status != DIMS_DOWNLOAD_TIMEOUT) { d->original_image_size = image_data.used; } diff --git a/src/mod_dims.h b/src/mod_dims.h index d5b89c9..1194cf2 100644 --- a/src/mod_dims.h +++ b/src/mod_dims.h @@ -240,6 +240,10 @@ struct dims_request_rec { /* Which endpoint served this, as a dims_endpoint_t. */ int endpoint; + /* Slots in the metrics format table, or -1 before the format is known. */ + int source_format_index; + int output_format_index; + /* The URL to the NOIMAGE image in case of failures. */ char *no_image_url; diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index 1ae5d76..db5676f 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -237,6 +237,35 @@ test_metrics_in_flight_settles(void) dims_response_free(response); } +/* A fetch records its origin status, its size, and the format it read. */ +static void +test_metrics_counts_the_source(void) +{ + dims_response *image = dims_request_ops("resize/40x40", "grid.png"); + dims_response *after; + + CHECK_INT(image->status, 200, "the image request"); + dims_response_free(image); + + after = scrape(); + + CHECK(dims_prom_value(after, "dims_origin_responses_total{code=\"200\"}") + >= 1, + "the origin 200 counter"); + CHECK(dims_prom_value(after, "dims_source_format_total{format=\"png\"}") + >= 1, + "the PNG source counter"); + CHECK(dims_prom_value(after, "dims_source_bytes_total") > 0, + "the source byte total"); + CHECK(dims_prom_value(after, "dims_source_bytes_count") >= 1, + "the source size histogram"); + CHECK(dims_prom_value(after, "dims_source_fetch_duration_seconds_count") + >= 1, + "the fetch duration histogram"); + + dims_response_free(after); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -245,6 +274,7 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsCountsASuccess", test_metrics_counts_a_success, NULL }, { "TestMetricsCountsARefusal", test_metrics_counts_a_refusal, NULL }, { "TestMetricsInFlightSettles", test_metrics_in_flight_settles, NULL }, + { "TestMetricsCountsTheSource", test_metrics_counts_the_source, NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From d37cb31c047c3236c043000f09b6d4807524482f Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 13:42:18 -0400 Subject: [PATCH 06/16] Record the output dims_imagemagick_duration_seconds, dims_source_frames, dims_output_format_total, dims_output_bytes_total, and dims_output_bytes. dims_send_image keeps the format and the blob length on the request record, and dims_process_image keeps the frame count. The pool cleanup reports them with the rest. --- src/handler.c | 2 ++ src/metrics.c | 19 +++++++++++++++ src/mod_dims.c | 6 +++++ src/mod_dims.h | 4 ++++ test/http/test_metrics.c | 51 ++++++++++++++++++++++++++++++++++++++++ 5 files changed, 82 insertions(+) diff --git a/src/handler.c b/src/handler.c index 6942d39..4728a33 100644 --- a/src/handler.c +++ b/src/handler.c @@ -361,6 +361,8 @@ dims_handler(request_rec *r) d->endpoint = -1; d->source_format_index = -1; d->output_format_index = -1; + d->output_bytes = 0; + d->source_frames = 0; d->image_url = NULL; d->filename = NULL; d->cache_control = NULL; diff --git a/src/metrics.c b/src/metrics.c index cc3995e..154e0db 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -351,6 +351,25 @@ record_request(void *baton) apr_atomic_inc64(&m->source_format[d->source_format_index]); } + if (d->source_frames > 0) { + dims_metrics_observe(&m->source_frames, &dims_frame_buckets, + d->source_frames); + } + + /* ImageMagick ran when it timed the work, whatever the outcome. */ + if (d->imagemagick_time > 0) { + dims_metrics_observe(&m->imagemagick_duration, &dims_duration_buckets, + (apr_uint64_t) d->imagemagick_time * 1000); + } + + /* The response, when one was written. */ + if (d->output_format_index >= 0) { + apr_atomic_inc64(&m->output_format[d->output_format_index]); + apr_atomic_add64(&m->output_bytes_total, d->output_bytes); + dims_metrics_observe(&m->output_bytes, &dims_byte_buckets, + d->output_bytes); + } + return APR_SUCCESS; } diff --git a/src/mod_dims.c b/src/mod_dims.c index 9d465d5..d4cfd41 100644 --- a/src/mod_dims.c +++ b/src/mod_dims.c @@ -503,6 +503,10 @@ dims_send_image(dims_request_rec *d) blob = MagickGetImagesBlob(d->wand, &length); d->imagemagick_time += (apr_time_now() - start_time) / 1000; + /* What the caller receives. The pool cleanup reports it. */ + d->output_format_index = dims_metrics_format_index(format); + d->output_bytes = (blob != NULL) ? (apr_uint64_t) length : 0; + /* Set the Content-Type based on the image format. */ content_type = apr_psprintf(d->pool, "image/%s", format); ap_content_type_tolower(content_type); @@ -981,6 +985,8 @@ dims_process_image(dims_request_rec *d) size_t images = MagickGetNumberImages(d->wand); bool should_flatten = false; + d->source_frames = (apr_uint64_t) images; + if (images > 1) { int i; for (i = 0; d->commands != NULL && i < d->commands->nelts; i++) { diff --git a/src/mod_dims.h b/src/mod_dims.h index 1194cf2..cd81c4b 100644 --- a/src/mod_dims.h +++ b/src/mod_dims.h @@ -244,6 +244,10 @@ struct dims_request_rec { int source_format_index; int output_format_index; + /* Bytes written to the caller, and frames in the source. */ + apr_uint64_t output_bytes; + apr_uint64_t source_frames; + /* The URL to the NOIMAGE image in case of failures. */ char *no_image_url; diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index db5676f..c42cfca 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -266,6 +266,55 @@ test_metrics_counts_the_source(void) dims_response_free(after); } +/* A response reports its format, its size, and the ImageMagick time. */ +static void +test_metrics_counts_the_output(void) +{ + dims_response *before = scrape(); + double was = dims_prom_value(before, + "dims_output_format_total{format=\"webp\"}"); + dims_response *image; + dims_response *after; + + image = dims_request_ops("resize/40x40/format/webp", "grid.png"); + CHECK_INT(image->status, 200, "the image request"); + dims_response_free(image); + + after = scrape(); + + CHECK(dims_prom_value(after, "dims_output_format_total{format=\"webp\"}") + >= was + 1, + "the webp output counter moved from %g", was); + CHECK(dims_prom_value(after, "dims_output_bytes_total") > 0, + "the output byte total"); + CHECK(dims_prom_value(after, "dims_output_bytes_count") >= 1, + "the output size histogram"); + CHECK(dims_prom_value(after, "dims_imagemagick_duration_seconds_count") + >= 1, + "the ImageMagick duration histogram"); + + dims_response_free(before); + dims_response_free(after); +} + +/* A single frame source counts in the first bucket. */ +static void +test_metrics_counts_frames(void) +{ + dims_response *image = dims_request_ops("resize/40x40", "grid.png"); + dims_response *after; + + dims_response_free(image); + after = scrape(); + + CHECK(dims_prom_value(after, "dims_source_frames_count") >= 1, + "the frame histogram counted a source"); + CHECK(dims_prom_value(after, "dims_source_frames_bucket{le=\"1\"}") >= 1, + "a single frame source is the first bucket"); + + dims_response_free(after); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -275,6 +324,8 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsCountsARefusal", test_metrics_counts_a_refusal, NULL }, { "TestMetricsInFlightSettles", test_metrics_in_flight_settles, NULL }, { "TestMetricsCountsTheSource", test_metrics_counts_the_source, NULL }, + { "TestMetricsCountsTheOutput", test_metrics_counts_the_output, NULL }, + { "TestMetricsCountsFrames", test_metrics_counts_frames, NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From 361589031f32bba647c5c3a73312c6a3e73c2254 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 13:44:57 -0400 Subject: [PATCH 07/16] Report ImageMagick resources and process memory Each child writes MagickGetResource for the four limited resources, and its resident and virtual size from /proc/self/statm, into the slot it claimed. The endpoint sums the live slots and reports the widest one, so two series cover a pool of any size. MagickGetResourceLimit reads the ceiling a worker runs under, so a dashboard divides use by limit. /proc/self/statm is Linux only. A platform without it reports no memory gauges rather than zero. --- src/metrics.c | 49 ++++++++++++++++++ src/metrics.h | 7 +++ src/metrics_report.c | 106 +++++++++++++++++++++++++++++++++++++++ test/http/test_metrics.c | 31 ++++++++++++ 4 files changed, 193 insertions(+) diff --git a/src/metrics.c b/src/metrics.c index 154e0db..dca4998 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -10,6 +10,7 @@ #include +#include #include #include @@ -362,6 +363,8 @@ record_request(void *baton) (apr_uint64_t) d->imagemagick_time * 1000); } + dims_metrics_sample_process(); + /* The response, when one was written. */ if (d->output_format_index >= 0) { apr_atomic_inc64(&m->output_format[d->output_format_index]); @@ -386,3 +389,49 @@ dims_metrics_request_begin(dims_request_rec *d) apr_pool_cleanup_register(d->r->pool, d, record_request, apr_pool_cleanup_null); } + +/* + * The four ImageMagick resources the module limits, in the order the exposition + * writer prints them. + */ +static const ResourceType resource_type[4] = { + AreaResource, MemoryResource, MapResource, DiskResource +}; + +void +dims_metrics_sample_process(void) +{ + dims_process_rec *slot = my_process; + FILE *statm; + unsigned long resident = 0; + unsigned long virtual = 0; + int i; + + if (slot == NULL) { + return; + } + + for (i = 0; i < 4; i++) { + slot->imagemagick_resource[i] = + (apr_uint64_t) MagickGetResource(resource_type[i]); + } + + /* + * The first two fields of statm are the virtual size and the resident set, + * both in pages. The file is Linux only, so a platform without it reports + * zero and the writer omits the two gauges. + */ + statm = fopen("/proc/self/statm", "r"); + if (statm == NULL) { + return; + } + + if (fscanf(statm, "%lu %lu", &virtual, &resident) == 2) { + long page = sysconf(_SC_PAGESIZE); + + slot->virtual_bytes = (apr_uint64_t) virtual * (apr_uint64_t) page; + slot->resident_bytes = (apr_uint64_t) resident * (apr_uint64_t) page; + } + + fclose(statm); +} diff --git a/src/metrics.h b/src/metrics.h index 155e6ac..5f70ac0 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -125,6 +125,13 @@ void dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, */ void dims_metrics_request_begin(dims_request_rec *d); +/* + * Writes this child ImageMagick resource use and process memory into its slot. + * Runs at the end of a request, so a scrape reports what the last request + * left. + */ +void dims_metrics_sample_process(void); + /* Answers a location that sets the dims-metrics handler. */ apr_status_t dims_metrics_handler(request_rec *r); diff --git a/src/metrics_report.c b/src/metrics_report.c index eb51e3a..0769161 100644 --- a/src/metrics_report.c +++ b/src/metrics_report.c @@ -75,6 +75,110 @@ histogram(request_rec *r, const char *name, const dims_histogram_rec *h, read64(&h->count)); } +/* + * The per process gauges. Each child writes its own slot at the end of a + * request, so the endpoint sums the live slots and reports the widest one. + */ +static void +write_process(request_rec *r, const dims_metrics_rec *m) +{ + static const char *const resource[4] = { "area", "memory", "map", "disk" }; + apr_uint64_t sum[4] = { 0, 0, 0, 0 }; + apr_uint64_t max[4] = { 0, 0, 0, 0 }; + apr_uint64_t resident_sum = 0, resident_max = 0; + apr_uint64_t virtual_sum = 0, virtual_max = 0; + apr_uint32_t live = 0; + apr_uint32_t i; + int k; + + for (i = 0; i < m->process_slots; i++) { + const dims_process_rec *slot = &m->process[i]; + apr_uint64_t resident; + apr_uint64_t virt; + + if (read64(&slot->pid) == 0) { + continue; + } + + live++; + + for (k = 0; k < 4; k++) { + apr_uint64_t value = read64(&slot->imagemagick_resource[k]); + + sum[k] += value; + if (value > max[k]) { + max[k] = value; + } + } + + resident = read64(&slot->resident_bytes); + resident_sum += resident; + if (resident > resident_max) { + resident_max = resident; + } + + virt = read64(&slot->virtual_bytes); + virtual_sum += virt; + if (virt > virtual_max) { + virtual_max = virt; + } + } + + head(r, "dims_imagemagick_resource_bytes", + "ImageMagick resource use, summed across the workers.", "gauge"); + for (k = 0; k < 4; k++) { + ap_rprintf(r, "dims_imagemagick_resource_bytes{resource=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", resource[k], sum[k]); + } + + head(r, "dims_imagemagick_resource_max_bytes", + "ImageMagick resource use by the widest worker.", "gauge"); + for (k = 0; k < 4; k++) { + ap_rprintf(r, "dims_imagemagick_resource_max_bytes{resource=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", resource[k], max[k]); + } + + /* The ceiling a worker runs under, from the same process the scrape + * reached. dims_child_init sets the same value in every worker. */ + head(r, "dims_imagemagick_resource_limit_bytes", + "The DimsImagemagick limit a worker runs under.", "gauge"); + ap_rprintf(r, "dims_imagemagick_resource_limit_bytes{resource=\"area\"} " + "%" APR_UINT64_T_FMT "\n", + (apr_uint64_t) MagickGetResourceLimit(AreaResource)); + ap_rprintf(r, "dims_imagemagick_resource_limit_bytes{resource=\"memory\"} " + "%" APR_UINT64_T_FMT "\n", + (apr_uint64_t) MagickGetResourceLimit(MemoryResource)); + ap_rprintf(r, "dims_imagemagick_resource_limit_bytes{resource=\"map\"} " + "%" APR_UINT64_T_FMT "\n", + (apr_uint64_t) MagickGetResourceLimit(MapResource)); + ap_rprintf(r, "dims_imagemagick_resource_limit_bytes{resource=\"disk\"} " + "%" APR_UINT64_T_FMT "\n", + (apr_uint64_t) MagickGetResourceLimit(DiskResource)); + + head(r, "dims_workers", "Worker processes holding a metrics slot.", + "gauge"); + ap_rprintf(r, "dims_workers %" APR_UINT64_T_FMT "\n", (apr_uint64_t) live); + + /* /proc/self/statm is Linux only, so a platform without it reports no + * memory rather than zero. */ + if (resident_sum > 0 || virtual_sum > 0) { + head(r, "dims_process_resident_bytes", + "Resident memory, summed across the workers.", "gauge"); + ap_rprintf(r, "dims_process_resident_bytes %" APR_UINT64_T_FMT "\n", + resident_sum); + + head(r, "dims_process_resident_max_bytes", + "Resident memory of the widest worker.", "gauge"); + ap_rprintf(r, "dims_process_resident_max_bytes %" APR_UINT64_T_FMT "\n", + resident_max); + + head(r, "dims_process_virtual_bytes", + "Virtual memory, summed across the workers.", "gauge"); + ap_rprintf(r, "dims_process_virtual_bytes %" APR_UINT64_T_FMT "\n", + virtual_sum); + } +} + static void write_metrics(request_rec *r) { @@ -173,6 +277,8 @@ write_metrics(request_rec *r) head(r, "dims_source_frames", "Frames in a source image.", "histogram"); histogram(r, "dims_source_frames", &m->source_frames, &dims_frame_buckets, 0, ""); + + write_process(r, m); } apr_status_t diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index c42cfca..8a5df7f 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -315,6 +315,36 @@ test_metrics_counts_frames(void) dims_response_free(after); } +/* + * The limits come from the configuration, so the reported ceiling matches what + * dims-test.conf sets. The use is per worker and the endpoint sums the slots. + */ +static void +test_metrics_reports_resources(void) +{ + dims_response *response; + + /* A request first, so a worker has sampled itself. */ + dims_response_free(dims_request_ops("resize/40x40", "grid.png")); + + response = scrape(); + + CHECK_INT((long) dims_prom_value(response, + "dims_imagemagick_resource_limit_bytes{resource=\"memory\"}"), + 536870912, "the memory limit"); + CHECK_INT((long) dims_prom_value(response, + "dims_imagemagick_resource_limit_bytes{resource=\"disk\"}"), + 2147483648L, "the disk limit"); + CHECK(dims_prom_value(response, "dims_workers") >= 1, + "a worker holds a slot"); + CHECK(dims_prom_value(response, "dims_process_resident_bytes") > 0, + "resident memory"); + CHECK(dims_prom_value(response, "dims_process_resident_max_bytes") > 0, + "the widest worker"); + + dims_response_free(response); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -326,6 +356,7 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsCountsTheSource", test_metrics_counts_the_source, NULL }, { "TestMetricsCountsTheOutput", test_metrics_counts_the_output, NULL }, { "TestMetricsCountsFrames", test_metrics_counts_frames, NULL }, + { "TestMetricsReportsResources", test_metrics_reports_resources, NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From 9fb4e9c4f61d97783eaba6be8d7de7faa2df49ae Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 13:47:23 -0400 Subject: [PATCH 08/16] Report the httpd worker pool dims_httpd_workers by scoreboard state, the process count and its ceiling, the thread count, connections by state, and the MPM generation. The scoreboard is the server's own record, so the endpoint reads it at scrape time rather than through the metrics block. Ready workers against the ceiling times the thread count is the headroom an operator reads before raising DIMS_SERVER_LIMIT. --- src/metrics_report.c | 92 ++++++++++++++++++++++++++++++++++++++++ test/http/test_metrics.c | 45 ++++++++++++++++++++ 2 files changed, 137 insertions(+) diff --git a/src/metrics_report.c b/src/metrics_report.c index 0769161..8bd0cde 100644 --- a/src/metrics_report.c +++ b/src/metrics_report.c @@ -8,6 +8,9 @@ #include "metrics.h" #include "module.h" +#include +#include + #include /* @@ -179,6 +182,94 @@ write_process(request_rec *r, const dims_metrics_rec *m) } } +/* + * The httpd worker pool, read from the scoreboard rather than the metrics + * block. The scoreboard is the server's own record, so a scrape reports what + * every worker is doing now. + */ +static void +write_httpd(request_rec *r) +{ + static const char *const state_name[SERVER_NUM_STATUS] = { + "dead", "starting", "ready", "busy_read", "busy_write", + "busy_keepalive", "busy_log", "busy_dns", "closing", "graceful", + "idle_kill" + }; + apr_uint64_t state[SERVER_NUM_STATUS]; + apr_uint64_t connections = 0, write_completion = 0, lingering = 0; + apr_uint64_t keep_alive = 0, suspended = 0; + int daemons = 0, threads = 0, generation = 0; + int processes = 0; + int i, j; + + memset(state, 0, sizeof(state)); + + ap_mpm_query(AP_MPMQ_MAX_DAEMONS, &daemons); + ap_mpm_query(AP_MPMQ_MAX_THREADS, &threads); + ap_mpm_query(AP_MPMQ_GENERATION, &generation); + + if (threads < 1) { + threads = 1; + } + + if (ap_exists_scoreboard_image()) { + for (i = 0; i < daemons; i++) { + process_score *ps = ap_get_scoreboard_process(i); + + if (ps->pid != 0 && !ps->quiescing) { + processes++; + connections += ps->connections; + write_completion += ps->write_completion; + lingering += ps->lingering_close; + keep_alive += ps->keep_alive; + suspended += ps->suspended; + } + + for (j = 0; j < threads; j++) { + worker_score *ws = ap_get_scoreboard_worker_from_indexes(i, j); + + if (ws != NULL && ws->status < SERVER_NUM_STATUS) { + state[ws->status]++; + } + } + } + } + + head(r, "dims_httpd_workers", "Worker threads by scoreboard state.", + "gauge"); + for (i = 0; i < SERVER_NUM_STATUS; i++) { + ap_rprintf(r, "dims_httpd_workers{state=\"%s\"} %" APR_UINT64_T_FMT "\n", + state_name[i], state[i]); + } + + head(r, "dims_httpd_processes", "Child processes serving requests.", + "gauge"); + ap_rprintf(r, "dims_httpd_processes %d\n", processes); + + head(r, "dims_httpd_processes_limit", "The daemon ceiling the MPM runs under.", + "gauge"); + ap_rprintf(r, "dims_httpd_processes_limit %d\n", daemons); + + head(r, "dims_httpd_threads_per_process", "Threads in one child.", "gauge"); + ap_rprintf(r, "dims_httpd_threads_per_process %d\n", threads); + + head(r, "dims_httpd_connections", "Connections by state.", "gauge"); + ap_rprintf(r, "dims_httpd_connections{state=\"total\"} " + "%" APR_UINT64_T_FMT "\n", connections); + ap_rprintf(r, "dims_httpd_connections{state=\"write_completion\"} " + "%" APR_UINT64_T_FMT "\n", write_completion); + ap_rprintf(r, "dims_httpd_connections{state=\"lingering_close\"} " + "%" APR_UINT64_T_FMT "\n", lingering); + ap_rprintf(r, "dims_httpd_connections{state=\"keep_alive\"} " + "%" APR_UINT64_T_FMT "\n", keep_alive); + ap_rprintf(r, "dims_httpd_connections{state=\"suspended\"} " + "%" APR_UINT64_T_FMT "\n", suspended); + + /* A restart increments this, so a dashboard sees the reload. */ + head(r, "dims_httpd_generation", "The MPM generation.", "gauge"); + ap_rprintf(r, "dims_httpd_generation %d\n", generation); +} + static void write_metrics(request_rec *r) { @@ -279,6 +370,7 @@ write_metrics(request_rec *r) 0, ""); write_process(r, m); + write_httpd(r); } apr_status_t diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index 8a5df7f..7e6ce80 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -345,6 +345,49 @@ test_metrics_reports_resources(void) dims_response_free(response); } +/* + * The scoreboard holds a slot per thread across the daemon ceiling, so the + * states add up to the ceiling times the thread count. The scrape itself is a + * busy worker, so at least one is not ready. + */ +static void +test_metrics_reports_the_worker_pool(void) +{ + dims_response *response = scrape(); + static const char *const states[] = { + "dead", "starting", "ready", "busy_read", "busy_write", + "busy_keepalive", "busy_log", "busy_dns", "closing", "graceful", + "idle_kill", NULL + }; + char name[128]; + double total = 0; + double limit; + double threads; + int i; + + for (i = 0; states[i] != NULL; i++) { + snprintf(name, sizeof(name), "dims_httpd_workers{state=\"%s\"}", + states[i]); + total += dims_prom_value(response, name); + } + + limit = dims_prom_value(response, "dims_httpd_processes_limit"); + threads = dims_prom_value(response, "dims_httpd_threads_per_process"); + + CHECK(limit >= 1, "a daemon ceiling"); + CHECK(threads >= 1, "a thread count"); + CHECK_INT((long) total, (long) (limit * threads), + "the worker states add up to the scoreboard"); + + CHECK(dims_prom_value(response, "dims_httpd_processes") >= 1, + "a live process"); + CHECK(dims_prom_value(response, "dims_httpd_workers{state=\"busy_write\"}") + >= 1, + "the scrape is a busy worker"); + + dims_response_free(response); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -357,6 +400,8 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsCountsTheOutput", test_metrics_counts_the_output, NULL }, { "TestMetricsCountsFrames", test_metrics_counts_frames, NULL }, { "TestMetricsReportsResources", test_metrics_reports_resources, NULL }, + { "TestMetricsReportsTheWorkerPool", test_metrics_reports_the_worker_pool, + NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From ff01eaad36e55520879b854ed434172ef4e4cef9 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 13:50:44 -0400 Subject: [PATCH 09/16] Sum the status counters from the metrics block dims_stats_rec and its shared memory block go away. dims_status_handler sums the requests table for the four numbers it prints, so the two endpoints report the same counters. dims_init set success_count to 1 at startup, so /dims-status/ reported one success before it served a request. Summing the table reports zero. The four apr_atomic_inc32 calls in mod_dims.c sat in dims_send_image, which a failure with no error image never reaches. The pool cleanup records every request whatever path it takes. --- src/mod_dims.c | 14 ----------- src/module.c | 37 ---------------------------- src/status.c | 53 +++++++++++++++++++++++++++++++++-------- src/status.h | 15 ------------ test/http/test_status.c | 48 +++++++++++++++++++++++++++++++++++++ 5 files changed, 91 insertions(+), 76 deletions(-) diff --git a/src/mod_dims.c b/src/mod_dims.c index d4cfd41..2b08991 100644 --- a/src/mod_dims.c +++ b/src/mod_dims.c @@ -562,19 +562,6 @@ dims_send_image(dims_request_rec *d) DestroyMagickWand(d->wand); d->wand = NULL; - /* After the image is sent record stats about this request. */ - if(d->status == DIMS_SUCCESS) { - apr_atomic_inc32(&stats->success_count); - } else { - apr_atomic_inc32(&stats->failure_count); - } - - if(d->status == DIMS_DOWNLOAD_TIMEOUT) { - apr_atomic_inc32(&stats->download_timeout_count); - } else if(d->status == DIMS_IMAGEMAGICK_TIMEOUT) { - apr_atomic_inc32(&stats->imagemagick_timeout_count); - } - /* Record metrics for logging. */ snprintf(buf, 128, "%d", d->status); apr_table_set(d->r->notes, "DIMS_STATUS", buf); @@ -926,7 +913,6 @@ dims_process_image(dims_request_rec *d) if (rc != OK) { dims_set_cache_headers(d); dims_free_request(d); - apr_atomic_inc32(&stats->success_count); return rc; } } diff --git a/src/module.c b/src/module.c index 4b3cc4a..b02ecea 100644 --- a/src/module.c +++ b/src/module.c @@ -31,7 +31,6 @@ static int dims_init(apr_pool_t *p, apr_pool_t *plog, apr_pool_t* ptemp, server_rec *s) { apr_status_t status; - apr_size_t retsize; void *first_pass = NULL; /* @@ -94,42 +93,6 @@ dims_init(apr_pool_t *p, apr_pool_t *plog, apr_pool_t* ptemp, server_rec *s) if (status != APR_SUCCESS) return HTTP_INTERNAL_SERVER_ERROR; - /* Create shared memory block */ - status = apr_shm_create(&shm, sizeof(dims_stats_rec), NULL, p); - if (status != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - "mod_dims : Error creating shm block\n"); - return status; - } - - /* Check size of shared memory block */ - retsize = apr_shm_size_get(shm); - if (retsize != sizeof(dims_stats_rec)) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - "mod_dims : Error allocating shared memory block\n"); - return status; - } - - /* Init shm block */ - stats = apr_shm_baseaddr_get(shm); - if (stats == NULL) { - ap_log_error(APLOG_MARK, APLOG_ERR, 0, s, - "mod_dims : Error creating status block.\n"); - return status; - } - memset(stats, 0, retsize); - - if (retsize < sizeof(dims_stats_rec)) { - ap_log_error(APLOG_MARK, APLOG_NOTICE, 0, s, - "mod_dims : Not enough memory allocated!! Giving up"); - return HTTP_INTERNAL_SERVER_ERROR; - } - - stats->success_count = 1; - stats->failure_count = 0; - stats->download_timeout_count = 0; - stats->imagemagick_timeout_count = 0; - status = dims_metrics_init(p, s); if (status != APR_SUCCESS) { return status; diff --git a/src/status.c b/src/status.c index 2a3b506..b6d0bbd 100644 --- a/src/status.c +++ b/src/status.c @@ -7,12 +7,45 @@ */ #include "status.h" +#include "metrics.h" #include "module.h" #include -dims_stats_rec *stats; -apr_shm_t *shm; +/* + * The four numbers this endpoint prints, summed from the metrics block. A + * request counts once, under the endpoint it arrived on. + */ +static apr_uint64_t +count_outcome(int outcome) +{ + apr_uint64_t total = 0; + int e; + + if (dims_metrics == NULL) { + return 0; + } + + for (e = 0; e < DIMS_ENDPOINT_COUNT; e++) { + total += apr_atomic_read64(&dims_metrics->requests[e][outcome]); + } + + return total; +} + +/* Every outcome apart from success. */ +static apr_uint64_t +count_failures(void) +{ + apr_uint64_t total = 0; + int i; + + for (i = 1; i < DIMS_OUTCOME_COUNT; i++) { + total += count_outcome(i); + } + + return total; +} static void show_time(request_rec *r, apr_interval_time_t tsecs) @@ -72,14 +105,14 @@ dims_status_handler(request_rec *r) ap_rprintf(r, "\nDetails\n-------\n"); - ap_rprintf(r, "Successful requests: %d\n", - apr_atomic_read32(&stats->success_count)); - ap_rprintf(r, "Failed requests: %d\n\n", - apr_atomic_read32(&stats->failure_count)); - ap_rprintf(r, "Download timeouts: %d\n", - apr_atomic_read32(&stats->download_timeout_count)); - ap_rprintf(r, "Imagemagick Timeouts: %d\n", - apr_atomic_read32(&stats->imagemagick_timeout_count)); + ap_rprintf(r, "Successful requests: %" APR_UINT64_T_FMT "\n", + count_outcome(DIMS_SUCCESS)); + ap_rprintf(r, "Failed requests: %" APR_UINT64_T_FMT "\n\n", + count_failures()); + ap_rprintf(r, "Download timeouts: %" APR_UINT64_T_FMT "\n", + count_outcome(DIMS_DOWNLOAD_TIMEOUT)); + ap_rprintf(r, "Imagemagick Timeouts: %" APR_UINT64_T_FMT "\n", + count_outcome(DIMS_IMAGEMAGICK_TIMEOUT)); ap_rflush(r); diff --git a/src/status.h b/src/status.h index 9a99c62..8c03065 100644 --- a/src/status.h +++ b/src/status.h @@ -11,21 +11,6 @@ #include "mod_dims.h" -/* - * Request counters, kept in shared memory so every worker adds to the same - * ones and the status endpoint reports a whole server rather than whichever - * worker answered. - */ -typedef struct { - apr_uint32_t success_count; - apr_uint32_t failure_count; - apr_uint32_t download_timeout_count; - apr_uint32_t imagemagick_timeout_count; -} dims_stats_rec; - -extern dims_stats_rec *stats; -extern apr_shm_t *shm; - /* Answers /dims-status/. */ apr_status_t dims_status_handler(request_rec *r); diff --git a/test/http/test_status.c b/test/http/test_status.c index 917646d..95af682 100644 --- a/test/http/test_status.c +++ b/test/http/test_status.c @@ -6,6 +6,7 @@ */ #include "../lib/common.h" +#include "../lib/prometheus.h" static void test_status_is_alive(void) @@ -34,8 +35,55 @@ test_status_hides_versions(void) dims_response_free(response); } +/* + * The two endpoints read the same counters, so the success line matches the + * sum of dims_requests_total across the endpoints. + */ +static void +test_status_agrees_with_the_metrics(void) +{ + dims_response *status; + dims_response *metrics; + const char *line; + char scraped[64]; + double total = 0; + static const char *const endpoints[] = { + "dims3", "dims4", "dims5", "local", NULL + }; + int i; + + dims_response_free(dims_request_ops("resize/40x40", "grid.png")); + + metrics = dims_get("/metrics"); + for (i = 0; endpoints[i] != NULL; i++) { + char name[128]; + + snprintf(name, sizeof(name), + "dims_requests_total{endpoint=\"%s\",outcome=\"success\"}", + endpoints[i]); + total += dims_prom_value(metrics, name); + } + + status = dims_get("/dims-status/"); + line = strstr((const char *) status->body, "Successful requests: "); + + if (line == NULL) { + FAIL("the status page reports no success count"); + } else { + snprintf(scraped, sizeof(scraped), "%s", + line + strlen("Successful requests: ")); + CHECK_INT(atol(scraped), (long) total, + "the status count matches the metrics"); + } + + dims_response_free(status); + dims_response_free(metrics); +} + const dims_test dims_tests_status[] = { { "TestStatusIsAlive", test_status_is_alive, NULL }, + { "TestStatusAgreesWithTheMetrics", test_status_agrees_with_the_metrics, + NULL }, { "TestStatusHidesVersions", test_status_hides_versions, "the versions print unless the directive is set" }, DIMS_TEST_END From 34e8d43f8173a26edf3f13f4a1f63c35a3d0af9f Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 14:06:28 -0400 Subject: [PATCH 10/16] Serve metrics on port 8001 in the image Port 8000 serves images. Port 8001 serves /metrics and /dims-status/, so a Service exposes 8000 and a scrape targets 8001. DIMS_METRICS_ENABLED defaults to off, so the image publishes no metrics until an operator turns it on. Behind an ingress controller httpd reads the controller address rather than the caller address, so Require ip cannot separate a scrape from a caller. A second listener moves the decision to the network. The Server image job scrapes 8001 and checks for a module counter and an httpd counter. --- .github/workflows/pr.yml | 16 ++++++++++++++++ docker/Dockerfile | 3 ++- docker/README.md | 11 +++++++++++ docker/dims.conf | 20 ++++++++++++++++++++ 4 files changed, 49 insertions(+), 1 deletion(-) diff --git a/.github/workflows/pr.yml b/.github/workflows/pr.yml index a2f1907..ced8826 100644 --- a/.github/workflows/pr.yml +++ b/.github/workflows/pr.yml @@ -191,6 +191,22 @@ jobs: "http://127.0.0.1:8000/dims3/development/resize/100x100/?url=http://$origin/grid.png" docker exec dims-ci sh -c 'test -s /tmp/out.png' + # The metrics endpoint answers on its own port, and only when the + # environment turns it on. + - name: Scrape the metrics endpoint + run: | + docker rm -f dims-ci + docker run -d --name dims-ci -p 8001:8001 \ + -e DIMS_METRICS_ENABLED=on mod-dims:ci + for i in $(seq 30); do + if curl -fsS -o /dev/null http://127.0.0.1:8001/metrics; then + break + fi + sleep 1 + done + curl -fsS http://127.0.0.1:8001/metrics | grep -q dims_requests_total + curl -fsS http://127.0.0.1:8001/metrics | grep -q dims_httpd_workers + # The runtime user must not be able to rewrite the module it runs. - name: Check the file permissions run: | diff --git a/docker/Dockerfile b/docker/Dockerfile index 616ddb4..e8a6e64 100644 --- a/docker/Dockerfile +++ b/docker/Dockerfile @@ -65,6 +65,7 @@ ENV DIMS_ALLOW_PRIVATE_ADDRESSES=off ENV DIMS_STATUS_VERBOSE=off ENV DIMS_ENABLE_DIMS3=off ENV DIMS_ENABLE_DIMS4=on +ENV DIMS_METRICS_ENABLED=off ENV DIMS_ENCRYPTION_ALGORITHM=AES/GCM/NoPadding ENV LC_ALL="C" @@ -105,7 +106,7 @@ RUN rm -rf /usr/local/apache2/build \ chown -R root:root /usr/local/apache2 /usr/local/imagemagick && \ chmod -R go-w /usr/local/apache2 /usr/local/imagemagick -EXPOSE 8000 +EXPOSE 8000 8001 USER 33 # A real request, not a configuration check. The status handler answers diff --git a/docker/README.md b/docker/README.md index 8272c10..0efe24f 100644 --- a/docker/README.md +++ b/docker/README.md @@ -36,6 +36,16 @@ $ docker run -e DIMS_SECRET=mysecret mod-dims:latest $ docker run -e DIMS_ENABLE_DIMS3=on -e DIMS_WHITELIST="images.pexels.com" mod-dims:latest ``` +## Set DIMS_METRICS_ENABLED to scrape the server + +```shell +$ docker run -p 8000:8000 -p 8001:8001 -e DIMS_METRICS_ENABLED=on mod-dims:latest +$ curl http://localhost:8001/metrics +``` + +Port 8001 serves `/metrics` and `/dims-status/`. Publish 8000 to callers and +keep 8001 for the monitoring network. + # Configuration | Environment Variables | Description | Default | @@ -45,6 +55,7 @@ $ docker run -e DIMS_ENABLE_DIMS3=on -e DIMS_WHITELIST="images.pexels.com" mod-d | `DIMS_WHITELIST` | Hosts /dims3/ may fetch from, separated by spaces. Empty matches no host. | "" | | `DIMS_ENABLE_DIMS3` | Whether the image serves /dims3/. It accepts an unsigned request, so the image ships it off. | off | | `DIMS_ENABLE_DIMS4` | Whether the image serves /dims4/. | on | +| `DIMS_METRICS_ENABLED` | Whether the image serves Prometheus metrics at `/metrics` on port 8001. | off | | `DIMS_DEFAULT_IMAGE_URL` | URL to the image sent when a request fails. A single dash means none. | "-" | | `DIMS_SECRET` | Shared secret for /dims4/ signatures. A single dash means none, and /dims4/ then refuses every request. | "-" | | `DIMS_DOWNLOAD_TIMEOUT` | Max time allowed for downloading source images, in milliseconds. | 60000 | diff --git a/docker/dims.conf b/docker/dims.conf index 749a847..4995ea9 100644 --- a/docker/dims.conf +++ b/docker/dims.conf @@ -87,3 +87,23 @@ DimsAddWhitelist ${DIMS_WHITELIST} SetHandler dims-status + +# The metrics listener. A Service exposes 8000 and a scrape targets 8001, so +# no ingress route reaches /metrics. Behind an ingress controller httpd reads +# the controller address rather than the caller address, so a second listener +# moves the decision to the network. +# +# /dims-status/ answers on both, because the health check reads it on 8000. +Listen 8001 + +DimsMetricsEnabled ${DIMS_METRICS_ENABLED} + + + + SetHandler dims-metrics + + + + SetHandler dims-status + + From cd339014bbcacd0d634ca84544e437612226dce7 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 14:12:56 -0400 Subject: [PATCH 11/16] Document the metrics endpoint A page for /metrics and a page for DimsMetricsEnabled, plus rows in the endpoints table, the defaults table, and the sidebar. dims_build_info and dims_start_time_seconds report the build and the restart time. DimsStatusVerbose off drops the build gauge, the same way it drops the version lines from /dims-status/. A label value escapes a backslash, a double quote, and a newline. The library versions come from ImageMagick and libcurl. dims3.md and dims4.md state that the client segment is a legacy of those two endpoints and that /dims5/ dropped it. --- .github/workflows/pr.yml | 2 +- docker/dims.conf | 2 +- docs/docs/configuration/index.md | 1 + docs/docs/configuration/metrics.md | 33 +++++++ docs/docs/endpoints/dims3.md | 5 + docs/docs/endpoints/dims4.md | 5 + docs/docs/endpoints/index.md | 3 +- docs/docs/endpoints/metrics.md | 145 +++++++++++++++++++++++++++++ docs/sidebars.js | 3 +- src/metrics_report.c | 71 +++++++++++++- test/http/test_metrics.c | 21 ++++- test/lib/prometheus.h | 2 +- 12 files changed, 285 insertions(+), 8 deletions(-) create mode 100644 docs/docs/configuration/metrics.md create mode 100644 docs/docs/endpoints/metrics.md diff --git a/.github/workflows/pr.yml b/.github/workflows/pr.yml index ced8826..843d8e4 100644 --- a/.github/workflows/pr.yml +++ b/.github/workflows/pr.yml @@ -191,7 +191,7 @@ jobs: "http://127.0.0.1:8000/dims3/development/resize/100x100/?url=http://$origin/grid.png" docker exec dims-ci sh -c 'test -s /tmp/out.png' - # The metrics endpoint answers on its own port, and only when the + # The metrics endpoint serves its own port, and only when the # environment turns it on. - name: Scrape the metrics endpoint run: | diff --git a/docker/dims.conf b/docker/dims.conf index 4995ea9..f64c3b4 100644 --- a/docker/dims.conf +++ b/docker/dims.conf @@ -93,7 +93,7 @@ DimsAddWhitelist ${DIMS_WHITELIST} # the controller address rather than the caller address, so a second listener # moves the decision to the network. # -# /dims-status/ answers on both, because the health check reads it on 8000. +# /dims-status/ serves both ports, because the health check reads it on 8000. Listen 8001 DimsMetricsEnabled ${DIMS_METRICS_ENABLED} diff --git a/docs/docs/configuration/index.md b/docs/docs/configuration/index.md index 11fc19b..a0636d5 100644 --- a/docs/docs/configuration/index.md +++ b/docs/docs/configuration/index.md @@ -71,6 +71,7 @@ Two more are worth enabling as your deployment allows. | `DimsImagemagickMemorySize` | 512 | | `DimsImagemagickTimeout` | 3000 | | `DimsIncludeDisposition` | false | +| `DimsMetricsEnabled` | `Off` | | `DimsMaxSourceBytes` | 0 | | `DimsNoImageCacheExpire` | 60 | | `DimsOptimizeResize` | 0 | diff --git a/docs/docs/configuration/metrics.md b/docs/docs/configuration/metrics.md new file mode 100644 index 0000000..3dffd99 --- /dev/null +++ b/docs/docs/configuration/metrics.md @@ -0,0 +1,33 @@ +# Metrics + +## DimsMetricsEnabled + +```apacheconf +DimsMetricsEnabled on +``` + +Whether the module serves [`/metrics`](/endpoints/metrics). Default `Off`. + +The directive is the switch, and a `` names the path. Both are +needed: + +```apacheconf +DimsMetricsEnabled on + + + SetHandler dims-metrics + +``` + +With the directive `Off` the handler declines the request and httpd answers +404, so a configuration that keeps the location stops publishing when the +directive goes off. + +The container reads `DIMS_METRICS_ENABLED`. The image sets it to `off`. It +serves metrics on port 8001. + +:::note +The endpoint reports the counters, the uptime, and the library versions. Serve +it on a port your callers cannot reach, or restrict the location to your +monitoring host. `DimsStatusVerbose Off` drops the version labels. +::: diff --git a/docs/docs/endpoints/dims3.md b/docs/docs/endpoints/dims3.md index 2c9e406..0167fab 100644 --- a/docs/docs/endpoints/dims3.md +++ b/docs/docs/endpoints/dims3.md @@ -19,6 +19,11 @@ any image, so the host allowlist is what decides which images are reachable. It reads the same query parameters as [`/dims4/`](/endpoints/dims4), apart from the signature. +The `client` segment is a legacy of `/dims3/` and `/dims4/`. +[`/dims5/`](/endpoints/dims5) dropped it. A server that serves several clients +gives each its own ``, which separates the clients, the allowlist, +and the keys. + ## The allowlist [`DimsAddWhitelist`](/configuration/image-sources) lists the hosts an image may diff --git a/docs/docs/endpoints/dims4.md b/docs/docs/endpoints/dims4.md index d95d5de..c75aaf0 100644 --- a/docs/docs/endpoints/dims4.md +++ b/docs/docs/endpoints/dims4.md @@ -18,6 +18,11 @@ neither can be changed without the secret. | `expires` | when the URL stops working, in seconds since the epoch | | `commands` | the [operations](/operations/) to run | +The `client` segment is a legacy of `/dims3/` and `/dims4/`. +[`/dims5/`](/endpoints/dims5) dropped it. A server that serves several clients +gives each its own ``, which separates the clients, the allowlist, +and the keys. + ## Query parameters | Name | Meaning | diff --git a/docs/docs/endpoints/index.md b/docs/docs/endpoints/index.md index 7523a3e..2868f41 100644 --- a/docs/docs/endpoints/index.md +++ b/docs/docs/endpoints/index.md @@ -1,6 +1,6 @@ # Endpoints -Four handlers, each set on a location. +Five handlers, each set on a location. | Handler | URL | Checked by | |---|---|---| @@ -8,6 +8,7 @@ Four handlers, each set on a location. | [`dims4`](/endpoints/dims4) | `/dims4/////?url=` | a signature | | [`dims3`](/endpoints/dims3) | `/dims3///?url=` | the host allowlist | | [`dims-status`](/endpoints/status) | `/dims-status/` | nothing | +| [`dims-metrics`](/endpoints/metrics) | `/metrics` | nothing | | [`dims-local`](/endpoints/local) | a file on disk | nothing | `/dims5/` is the one to use. Its signature covers the commands, the image URL, diff --git a/docs/docs/endpoints/metrics.md b/docs/docs/endpoints/metrics.md new file mode 100644 index 0000000..a2f2b82 --- /dev/null +++ b/docs/docs/endpoints/metrics.md @@ -0,0 +1,145 @@ +# /metrics + +``` +/metrics +``` + +Reports the module, ImageMagick, and httpd in the Prometheus text format. A +Prometheus server scrapes it, and so does an OpenTelemetry Collector through +its `prometheus` receiver. + +Two lines turn it on. The directive is the switch, and the location names the +path. + +```apacheconf +DimsMetricsEnabled on + + + SetHandler dims-metrics + +``` + +[`DimsMetricsEnabled`](/configuration/metrics) defaults to `Off`, so a server +that upgrades publishes no metrics until an operator turns it on. + +## What it reports + +``` +# HELP dims_requests_total Requests by endpoint and outcome. +# TYPE dims_requests_total counter +dims_requests_total{endpoint="dims5",outcome="success"} 18423 +dims_requests_total{endpoint="dims5",outcome="download_timeout"} 4 + +# HELP dims_request_duration_seconds Time to serve a request. +# TYPE dims_request_duration_seconds histogram +dims_request_duration_seconds_bucket{endpoint="dims5",le="0.025"} 17155 +dims_request_duration_seconds_bucket{endpoint="dims5",le="+Inf"} 18427 +dims_request_duration_seconds_sum{endpoint="dims5"} 314.288000 +dims_request_duration_seconds_count{endpoint="dims5"} 18427 +``` + +| Metric | Type | Labels | +|---|---|---| +| `dims_requests_total` | counter | `endpoint`, `outcome` | +| `dims_responses_total` | counter | `endpoint`, `code` | +| `dims_requests_in_flight` | gauge | `endpoint` | +| `dims_request_duration_seconds` | histogram | `endpoint` | +| `dims_source_fetch_duration_seconds` | histogram | | +| `dims_source_bytes` | histogram | | +| `dims_source_bytes_total` | counter | | +| `dims_source_format_total` | counter | `format` | +| `dims_origin_responses_total` | counter | `code` | +| `dims_imagemagick_duration_seconds` | histogram | | +| `dims_source_frames` | histogram | | +| `dims_output_bytes` | histogram | | +| `dims_output_bytes_total` | counter | | +| `dims_output_format_total` | counter | `format` | +| `dims_imagemagick_resource_bytes` | gauge | `resource` | +| `dims_imagemagick_resource_max_bytes` | gauge | `resource` | +| `dims_imagemagick_resource_limit_bytes` | gauge | `resource` | +| `dims_process_resident_bytes` | gauge | | +| `dims_process_resident_max_bytes` | gauge | | +| `dims_process_virtual_bytes` | gauge | | +| `dims_workers` | gauge | | +| `dims_httpd_workers` | gauge | `state` | +| `dims_httpd_processes` | gauge | | +| `dims_httpd_processes_limit` | gauge | | +| `dims_httpd_threads_per_process` | gauge | | +| `dims_httpd_connections` | gauge | `state` | +| `dims_httpd_generation` | gauge | | + +`endpoint` holds `dims3`, `dims4`, `dims5`, or `local`. + +`outcome` holds `success`, `failure`, `download_timeout`, +`imagemagick_timeout`, `bad_client`, `bad_url`, `bad_arguments`, +`hostname_not_in_whitelist`, `file_not_found`, or `network_refused`. + +`code` holds `200`, `400`, `403`, `404`, `429`, `500`, `502`, `503`, `504`, or +`other`. The list bounds the label, because +[`DimsOriginStatusMode`](/configuration/cache-control) `forward` reports the +status the origin returned. + +`format` holds `jpeg`, `png`, `gif`, `webp`, `avif`, `heic`, `tiff`, `svg`, or +`other`. + +`resource` holds `area`, `memory`, `map`, or `disk`. + +## The whole server + +Every metric describes the server, with no `client` label. The client id is a +legacy of `/dims3/` and `/dims4/`, and `/dims5/` dropped it. + +A deployment that serves several clients gives each its own ``, +which separates the clients, the allowlist, and the keys. The counters stay +shared, because the module creates one block for the process. Separate metrics +need separate instances. + +## Per process and per server + +Most metrics come from a block every worker adds to, so they describe the whole +server. + +`dims_imagemagick_resource_bytes`, `dims_process_resident_bytes`, and +`dims_process_virtual_bytes` are per worker. Each child writes its own numbers +when a request ends, and this endpoint sums the live workers. The matching +`_max_bytes` gauge reports the widest single worker, so one worker at its +ceiling is visible beside three idle ones. `dims_workers` counts the workers in +the sum. + +`dims_process_resident_bytes` and `dims_process_virtual_bytes` read +`/proc/self/statm`. A platform without it omits both. + +## Kubernetes + +The container serves images on 8000 and metrics on 8001, so a Service exposes +8000 and a scrape targets 8001. + +```shell +docker run -p 8000:8000 -p 8001:8001 -e DIMS_METRICS_ENABLED=on \ + ghcr.io/beetlebugorg/mod_dims:latest +``` + +An OpenTelemetry Collector reads it through the `prometheus` receiver: + +```yaml +receivers: + prometheus: + config: + scrape_configs: + - job_name: mod_dims + static_configs: + - targets: ['mod-dims:8001'] +``` + +## Worker headroom + +`dims_httpd_workers{state="ready"}` against `dims_httpd_processes_limit` times +`dims_httpd_threads_per_process` is the headroom the pool has left. Ready +workers near zero while `dims_requests_in_flight` climbs means the pool is +full. + +:::note +`dims_build_info` names the mod_dims, ImageMagick, and libcurl versions. +[`DimsStatusVerbose`](/configuration/output) `Off` drops it, the same way it +drops the version lines from [`/dims-status/`](/endpoints/status). +::: diff --git a/docs/sidebars.js b/docs/sidebars.js index 8b047c6..ef24be0 100644 --- a/docs/sidebars.js +++ b/docs/sidebars.js @@ -7,7 +7,7 @@ const sidebars = { type: 'category', label: 'Endpoints', link: {type: 'doc', id: 'endpoints/index'}, - items: ['endpoints/dims5', 'endpoints/dims4', 'endpoints/dims3', 'endpoints/status', 'endpoints/local'], + items: ['endpoints/dims5', 'endpoints/dims4', 'endpoints/dims3', 'endpoints/status', 'endpoints/metrics', 'endpoints/local'], }, { type: 'category', @@ -60,6 +60,7 @@ const sidebars = { 'configuration/cache-control', 'configuration/output', 'configuration/resources', + 'configuration/metrics', ], }, ], diff --git a/src/metrics_report.c b/src/metrics_report.c index 8bd0cde..1a6b26c 100644 --- a/src/metrics_report.c +++ b/src/metrics_report.c @@ -11,6 +11,10 @@ #include #include +#include + +#include + #include /* @@ -27,6 +31,41 @@ read64(const apr_uint64_t *value) return apr_atomic_read64((apr_uint64_t *) value); } +/* + * A label value with the three characters the format reserves escaped: a + * backslash, a double quote, and a newline. Every label the module writes is + * its own, apart from the library versions, which come from ImageMagick and + * libcurl. + */ +static const char * +escape(apr_pool_t *pool, const char *value) +{ + apr_size_t len; + char *out; + apr_size_t w = 0; + apr_size_t i; + + if (value == NULL) { + return ""; + } + + len = strlen(value); + out = apr_palloc(pool, len * 2 + 1); + + for (i = 0; i < len; i++) { + switch (value[i]) { + case '\\': out[w++] = '\\'; out[w++] = '\\'; break; + case '"': out[w++] = '\\'; out[w++] = '"'; break; + case '\n': out[w++] = '\\'; out[w++] = 'n'; break; + default: out[w++] = value[i]; break; + } + } + + out[w] = '\0'; + + return out; +} + static void head(request_rec *r, const char *name, const char *help, const char *type) { @@ -270,8 +309,35 @@ write_httpd(request_rec *r) ap_rprintf(r, "dims_httpd_generation %d\n", generation); } +/* + * The build and the start time. + * + * dims_build_info names every library version, so DimsStatusVerbose off drops + * it the same way it drops the version lines from /dims-status/. + */ +static void +write_build(request_rec *r, const dims_config_rec *config) +{ + head(r, "dims_start_time_seconds", + "When the server last started, in seconds since the epoch.", + "gauge"); + ap_rprintf(r, "dims_start_time_seconds %" APR_TIME_T_FMT "\n", + apr_time_sec(ap_scoreboard_image->global->restart_time)); + + if (config == NULL || !config->status_verbose) { + return; + } + + head(r, "dims_build_info", "The running build, always 1.", "gauge"); + ap_rprintf(r, "dims_build_info{version=\"%s\",commit=\"%s\"," + "imagemagick=\"%s\",libcurl=\"%s\"} 1\n", + escape(r->pool, DIMS_VERSION), escape(r->pool, DIMS_COMMIT), + escape(r->pool, GetMagickVersion(NULL)), + escape(r->pool, curl_version())); +} + static void -write_metrics(request_rec *r) +write_metrics(request_rec *r, const dims_config_rec *config) { dims_metrics_rec *m = dims_metrics; char labels[64]; @@ -371,6 +437,7 @@ write_metrics(request_rec *r) write_process(r, m); write_httpd(r); + write_build(r, config); } apr_status_t @@ -390,7 +457,7 @@ dims_metrics_handler(request_rec *r) ap_set_content_type(r, "text/plain; version=0.0.4; charset=utf-8"); if (!r->header_only) { - write_metrics(r); + write_metrics(r, config); ap_rflush(r); } diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index 7e6ce80..89eab16 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -195,7 +195,7 @@ test_metrics_counts_a_success(void) } /* - * A host outside the allowlist reports its own outcome on /dims3/, which is + * A host outside the allowlist reports its own outcome on /dims3/. That is * the endpoint that enforces the list. */ static void @@ -388,6 +388,24 @@ test_metrics_reports_the_worker_pool(void) dims_response_free(response); } +/* The build gauge names the versions, and the start time is a real clock. */ +static void +test_metrics_reports_the_build(void) +{ + dims_response *response = scrape(); + + CHECK(dims_prom_contains(response, "dims_build_info{version=\""), + "the build gauge"); + CHECK(dims_prom_contains(response, "imagemagick=\"ImageMagick"), + "the ImageMagick version"); + + /* Later than 2020, so the value is a clock rather than an uptime. */ + CHECK(dims_prom_value(response, "dims_start_time_seconds") > 1577836800.0, + "the start time is an epoch second"); + + dims_response_free(response); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -402,6 +420,7 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsReportsResources", test_metrics_reports_resources, NULL }, { "TestMetricsReportsTheWorkerPool", test_metrics_reports_the_worker_pool, NULL }, + { "TestMetricsReportsTheBuild", test_metrics_reports_the_build, NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; diff --git a/test/lib/prometheus.h b/test/lib/prometheus.h index 1a955ab..e29a148 100644 --- a/test/lib/prometheus.h +++ b/test/lib/prometheus.h @@ -14,7 +14,7 @@ int dims_prom_contains(const dims_response *response, const char *text); /* - * The value of the sample whose line starts with prefix, which is a metric + * The value of the sample whose line starts with prefix. A prefix is a metric * name and its label set: * * dims_requests_total{endpoint="dims4",outcome="success"} From 1752102a10ffd69b063a1cb79ab4fb606138f8f3 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 14:52:29 -0400 Subject: [PATCH 12/16] Record the guard, the signature, each operation, and the cache dims_source_fetch_total and dims_source_fetch_errors_total by libcurl code. dims_netguard_refusals_total by reason, and dims_allowlist_checks_total by mode and result. dims_signature_checks_total by endpoint and result, and dims_eurl_decrypt_total. dims_operations_total, dims_operation_failures_total, and dims_operation_duration_seconds per operation. dims_imagemagick_exceptions_total by kind and severity. dims_overlay_cache_lookups_total, dims_overlay_cache_evictions_total, dims_error_images_total, and dims_error_image_failures_total. An operation counts one call. A multi-frame source runs the command loop once per frame, and strip and format run without a command, so the trigger label separates the two. apr_time_now costs 15.7 ns on this host, measured over 20 million calls. Two per operation call adds about 31 ns against a transform measured in milliseconds. The allowlist reports at two sites. handler.c refuses a /dims3/ request before the fetch, and the guard runs its own check at fetch time under DimsAllowlistSigned. --- src/dims5.c | 6 + src/handler.c | 11 ++ src/metrics.c | 302 +++++++++++++++++++++++++++++++++++++++ src/metrics.h | 98 +++++++++++++ src/metrics_report.c | 133 +++++++++++++++++ src/mod_dims.c | 56 +++++++- src/netguard.c | 45 ++++-- src/overlay_cache.c | 9 ++ test/http/test_metrics.c | 99 +++++++++++++ 9 files changed, 743 insertions(+), 16 deletions(-) diff --git a/src/dims5.c b/src/dims5.c index d12222d..4ef57d1 100644 --- a/src/dims5.c +++ b/src/dims5.c @@ -6,6 +6,7 @@ */ #include "dims5.h" +#include "metrics.h" #include "encryption.h" #include "signature.h" #include "url.h" @@ -92,11 +93,13 @@ dims5_verify(dims_request_rec *d) decrypted = aes_128_gcm_decrypt(d->r, derived, (unsigned char *) eurl); if (decrypted == NULL) { + dims_metrics_eurl(0); ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "Cannot decrypt eurl, on request: %s", d->r->uri); return DIMS_BAD_URL; } + dims_metrics_eurl(1); image_url = decrypted; } else { image_url = query_value(d, "url"); @@ -123,11 +126,14 @@ dims5_verify(dims_request_rec *d) dims_signed_query(d->pool, d->r->args))); if (expected == NULL || !dims_signature_equal(expected, signature)) { + dims_metrics_signature(DIMS_ENDPOINT_DIMS5, DIMS_SIG_MISMATCH); ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "Signature mismatch, on request: %s", d->r->uri); return DIMS_BAD_URL; } + dims_metrics_signature(DIMS_ENDPOINT_DIMS5, DIMS_SIG_OK); + d->image_url = image_url; d->unparsed_commands = commands; d->client_id = NULL; diff --git a/src/handler.c b/src/handler.c index 4728a33..a6ad5dd 100644 --- a/src/handler.c +++ b/src/handler.c @@ -48,6 +48,7 @@ dims_handle_request(dims_request_rec *d) if(!(d->client_config = apr_hash_get(d->config->clients, d->client_id, APR_HASH_KEY_STRING))) { + dims_metrics_signature(d->endpoint, DIMS_SIG_BAD_CLIENT); return dims_cleanup(d, "Application ID is not valid", DIMS_BAD_CLIENT); } @@ -68,11 +69,13 @@ dims_handle_request(dims_request_rec *d) now = apr_time_sec(now_time); if ( expires - now < 0 ) { ap_log_rerror( APLOG_MARK, APLOG_DEBUG,0, d->r, "Image expired: %s now=%ld", d->r->uri,now); + dims_metrics_signature(d->endpoint, DIMS_SIG_EXPIRED); return dims_cleanup( d, "Image Key has expired", DIMS_BAD_URL); } if ( expires - now > d->config->max_expiry_period && d->config->max_expiry_period >0 ) { ap_log_rerror( APLOG_MARK, APLOG_DEBUG,0, d->r, "Image expiry too far in the future:%s %s now=%ld",expires_str, d->r->uri,now); + dims_metrics_signature(d->endpoint, DIMS_SIG_TOO_FAR_FUTURE); return dims_cleanup(d, "Image key too far in the future", DIMS_BAD_URL); } @@ -117,6 +120,7 @@ dims_handle_request(dims_request_rec *d) if (d->client_config->secret_key == NULL) { ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "Developer key not set for client '%s'", d->client_config->id); + dims_metrics_signature(d->endpoint, DIMS_SIG_MISSING_KEY); return dims_cleanup(d, "Missing Developer Key", DIMS_BAD_CLIENT); } @@ -145,8 +149,10 @@ dims_handle_request(dims_request_rec *d) gen_hash[7] = '\0'; ap_log_rerror(APLOG_MARK, APLOG_DEBUG,0, d->r, "Key Mismatch: wanted %6s got %6s [%s?url=%s]", gen_hash, hash, d->r->uri, d->image_url); + dims_metrics_signature(d->endpoint, DIMS_SIG_MISMATCH); return dims_cleanup(d, "Key mismatch", DIMS_BAD_URL); } + dims_metrics_signature(d->endpoint, DIMS_SIG_OK); ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "secret key (%s) to validated (%s:%s)", hash, d->unparsed_commands,d->image_url); } @@ -257,6 +263,11 @@ dims_handle_request(dims_request_rec *d) found = 1; } else { found = dims_host_allowed(d->config->whitelist, hostname); + + /* This check refuses the request, so it counts as enforce. The + * guard runs its own check at fetch time under + * DimsAllowlistSigned. */ + dims_metrics_allowlist(DIMS_ALLOWLIST_ENFORCE, found); } if(found) { diff --git a/src/metrics.c b/src/metrics.c index dca4998..a7701f2 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -10,6 +10,8 @@ #include +#include + #include #include #include @@ -435,3 +437,303 @@ dims_metrics_sample_process(void) fclose(statm); } + +/* libcurl codes reported by name. The rest count under "other". */ +static const int curl_code_value[DIMS_CURL_CODE_COUNT - 1] = { + CURLE_OPERATION_TIMEDOUT, + CURLE_COULDNT_RESOLVE_HOST, + CURLE_COULDNT_CONNECT, + CURLE_SSL_CONNECT_ERROR, + CURLE_TOO_MANY_REDIRECTS, + CURLE_RECV_ERROR, + CURLE_SEND_ERROR, + CURLE_PARTIAL_FILE +}; + +static const char *const curl_code_name[DIMS_CURL_CODE_COUNT] = { + "operation_timedout", "couldnt_resolve_host", "couldnt_connect", + "ssl_connect_error", "too_many_redirects", "recv_error", "send_error", + "partial_file", "other" +}; + +static const char *const fetch_result_name[DIMS_FETCH_RESULT_COUNT] = { + "ok", "timeout", "transport_error", "refused", "http_error" +}; + +/* Indexed by dims_net_result, which starts at DIMS_NET_BAD_SCHEME. */ +static const char *const net_reason_name[DIMS_NET_REASON_COUNT] = { + "bad_scheme", "bad_url", "reserved_address", "private_address", + "host_not_allowed", "too_many_redirects" +}; + +static const char *const sig_result_name[DIMS_SIG_RESULT_COUNT] = { + "ok", "mismatch", "expired", "too_far_future", "missing_key", "bad_client" +}; + +/* The order dims_module.c registers them in the ops hash. */ +static const char *const operation_name[DIMS_OP_COUNT] = { + "strip", "resize", "crop", "thumbnail", "legacy_thumbnail", "legacy_crop", + "quality", "sharpen", "format", "brightness", "flipflop", "sepia", + "grayscale", "autolevel", "rotate", "invert", "watermark" +}; + +static const char *const exception_kind_name[DIMS_EXC_KIND_COUNT] = { + "blob", "cache", "coder", "configure", "corrupt_image", "delegate", + "draw", "file_open", "filter", "image", "missing_delegate", "module", + "monitor", "option", "policy", "random", "registry", "resource_limit", + "stream", "type", "wand", "other" +}; + +static const char *const exception_severity_name[DIMS_EXC_SEVERITY_COUNT] = { + "warning", "error", "fatal" +}; + +int +dims_metrics_curl_code_index(int code) +{ + int i; + + for (i = 0; i < DIMS_CURL_CODE_COUNT - 1; i++) { + if (curl_code_value[i] == code) { + return i; + } + } + + return DIMS_CURL_CODE_COUNT - 1; +} + +int +dims_metrics_operation_index(const char *operation) +{ + int i; + + if (operation == NULL) { + return -1; + } + + for (i = 0; i < DIMS_OP_COUNT; i++) { + if (strcmp(operation_name[i], operation) == 0) { + return i; + } + } + + return -1; +} + +/* + * ImageMagick names an exception by a kind and a severity in one enum, such as + * ResourceLimitError. The two are separate signals: a warning about a coder + * and a fatal cache failure read differently. + */ +void +dims_metrics_exception_slot(int exception_type, int *kind, int *severity) +{ + struct { int warning; int kind; } table[] = { + { BlobWarning, 0 }, + { CacheWarning, 1 }, + { CoderWarning, 2 }, + { ConfigureWarning, 3 }, + { CorruptImageWarning, 4 }, + { DelegateWarning, 5 }, + { DrawWarning, 6 }, + { FileOpenWarning, 7 }, + { FilterWarning, 8 }, + { ImageWarning, 9 }, + { MissingDelegateWarning, 10 }, + { ModuleWarning, 11 }, + { MonitorWarning, 12 }, + { OptionWarning, 13 }, + { PolicyWarning, 14 }, + { RandomWarning, 15 }, + { RegistryWarning, 16 }, + { ResourceLimitWarning, 17 }, + { StreamWarning, 18 }, + { TypeWarning, 19 }, + { WandWarning, 20 } + }; + size_t i; + + *kind = DIMS_EXC_KIND_COUNT - 1; + *severity = 1; + + /* Each kind occupies three consecutive values: warning, error, and fatal + * error. WandWarning has no fatal member, so it holds two. */ + for (i = 0; i < sizeof(table) / sizeof(table[0]); i++) { + int offset = exception_type - table[i].warning; + + if (offset >= 0 && offset <= 2) { + *kind = table[i].kind; + *severity = offset; + return; + } + } +} + +const char * +dims_metrics_curl_code_name(int index) +{ + return (index < 0 || index >= DIMS_CURL_CODE_COUNT) ? "" + : curl_code_name[index]; +} + +const char * +dims_metrics_operation_name(int index) +{ + return (index < 0 || index >= DIMS_OP_COUNT) ? "" : operation_name[index]; +} + +const char * +dims_metrics_exception_kind_name(int index) +{ + return (index < 0 || index >= DIMS_EXC_KIND_COUNT) ? "" + : exception_kind_name[index]; +} + +const char * +dims_metrics_exception_severity_name(int index) +{ + return (index < 0 || index >= DIMS_EXC_SEVERITY_COUNT) ? "" + : exception_severity_name[index]; +} + +const char * +dims_metrics_fetch_result_name(int index) +{ + return (index < 0 || index >= DIMS_FETCH_RESULT_COUNT) ? "" + : fetch_result_name[index]; +} + +const char * +dims_metrics_net_reason_name(int index) +{ + return (index < 0 || index >= DIMS_NET_REASON_COUNT) ? "" + : net_reason_name[index]; +} + +const char * +dims_metrics_sig_result_name(int index) +{ + return (index < 0 || index >= DIMS_SIG_RESULT_COUNT) ? "" + : sig_result_name[index]; +} + +void +dims_metrics_signature(int endpoint, dims_sig_result result) +{ + if (dims_metrics == NULL || endpoint < 0 || + endpoint >= DIMS_ENDPOINT_COUNT) { + return; + } + + apr_atomic_inc64(&dims_metrics->signature[endpoint][result]); +} + +void +dims_metrics_eurl(int ok) +{ + if (dims_metrics != NULL) { + apr_atomic_inc64(&dims_metrics->eurl[ok ? 0 : 1]); + } +} + +void +dims_metrics_netguard(int reason) +{ + /* DIMS_NET_OK is zero and names no refusal. */ + if (dims_metrics == NULL || reason < 1 || + reason > DIMS_NET_REASON_COUNT) { + return; + } + + apr_atomic_inc64(&dims_metrics->netguard[reason - 1]); +} + +void +dims_metrics_allowlist(int mode, int allowed) +{ + if (dims_metrics == NULL || mode < 0 || mode > 2) { + return; + } + + apr_atomic_inc64(&dims_metrics->allowlist[mode][allowed ? 0 : 1]); +} + +void +dims_metrics_operation(int op_index, int from_default, apr_time_t began, + int failed) +{ + dims_metrics_rec *m = dims_metrics; + + if (m == NULL || op_index < 0 || op_index >= DIMS_OP_COUNT) { + return; + } + + apr_atomic_inc64(&m->operations[op_index][from_default ? 1 : 0]); + + if (failed) { + apr_atomic_inc64(&m->operation_failures[op_index]); + } + + dims_metrics_observe(&m->operation_duration[op_index], + &dims_duration_buckets, (apr_uint64_t) (apr_time_now() - began)); +} + +void +dims_metrics_exception(int exception_type) +{ + int kind; + int severity; + + if (dims_metrics == NULL || exception_type == UndefinedException) { + return; + } + + dims_metrics_exception_slot(exception_type, &kind, &severity); + apr_atomic_inc64(&dims_metrics->exceptions[kind][severity]); +} + +void +dims_metrics_overlay_lookup(int result) +{ + if (dims_metrics != NULL && result >= 0 && result < 3) { + apr_atomic_inc64(&dims_metrics->overlay_lookups[result]); + } +} + +void +dims_metrics_overlay_eviction(void) +{ + if (dims_metrics != NULL) { + apr_atomic_inc64(&dims_metrics->overlay_evictions); + } +} + +void +dims_metrics_fetch(dims_fetch_result result, int curl_code) +{ + if (dims_metrics == NULL) { + return; + } + + apr_atomic_inc64(&dims_metrics->fetch_results[result]); + + if (result == DIMS_FETCH_TIMEOUT || result == DIMS_FETCH_TRANSPORT_ERROR || + result == DIMS_FETCH_REFUSED) { + apr_atomic_inc64(&dims_metrics->fetch_errors[ + dims_metrics_curl_code_index(curl_code)]); + } +} + +void +dims_metrics_error_image(int source, int failed) +{ + if (dims_metrics == NULL || source < 0 || source > 2) { + return; + } + + apr_atomic_inc64(&dims_metrics->error_images[source]); + + if (failed) { + apr_atomic_inc64(&dims_metrics->error_image_failures); + } +} diff --git a/src/metrics.h b/src/metrics.h index 5f70ac0..0d029f1 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -33,6 +33,25 @@ typedef enum { /* Image formats reported by name. The last slot holds every other format. */ #define DIMS_FORMAT_COUNT 9 +/* Why a source fetch ended. */ +#define DIMS_FETCH_RESULT_COUNT 5 + +/* libcurl error codes reported by name. The last slot holds every other one. */ +#define DIMS_CURL_CODE_COUNT 9 + +/* dims_net_result without DIMS_NET_OK. */ +#define DIMS_NET_REASON_COUNT 6 + +/* How a signature check ended. */ +#define DIMS_SIG_RESULT_COUNT 6 + +/* The seventeen operations in the ops hash. */ +#define DIMS_OP_COUNT 17 + +/* ImageMagick exception kinds, and the three severities. */ +#define DIMS_EXC_KIND_COUNT 22 +#define DIMS_EXC_SEVERITY_COUNT 3 + /* The widest bucket table below, plus the +Inf bucket. */ #define DIMS_BUCKET_MAX 13 @@ -73,12 +92,27 @@ typedef struct { apr_uint64_t source_bytes_total; apr_uint64_t output_bytes_total; + apr_uint64_t fetch_results[DIMS_FETCH_RESULT_COUNT]; + apr_uint64_t fetch_errors[DIMS_CURL_CODE_COUNT]; + apr_uint64_t netguard[DIMS_NET_REASON_COUNT]; + apr_uint64_t allowlist[3][2]; + apr_uint64_t signature[DIMS_ENDPOINT_COUNT][DIMS_SIG_RESULT_COUNT]; + apr_uint64_t eurl[2]; + apr_uint64_t operations[DIMS_OP_COUNT][2]; + apr_uint64_t operation_failures[DIMS_OP_COUNT]; + apr_uint64_t exceptions[DIMS_EXC_KIND_COUNT][DIMS_EXC_SEVERITY_COUNT]; + apr_uint64_t overlay_lookups[3]; + apr_uint64_t overlay_evictions; + apr_uint64_t error_images[3]; + apr_uint64_t error_image_failures; + dims_histogram_rec request_duration[DIMS_ENDPOINT_COUNT]; dims_histogram_rec download_duration; dims_histogram_rec imagemagick_duration; dims_histogram_rec source_bytes; dims_histogram_rec output_bytes; dims_histogram_rec source_frames; + dims_histogram_rec operation_duration[DIMS_OP_COUNT]; /* The slot count comes from AP_MPMQ_HARD_LIMIT_DAEMONS. */ apr_uint32_t process_slots; @@ -104,6 +138,9 @@ int dims_metrics_outcome_index(int status); int dims_metrics_code_index(int code); int dims_metrics_origin_code_index(int code); int dims_metrics_format_index(const char *format); +int dims_metrics_curl_code_index(int code); +int dims_metrics_operation_index(const char *operation); +void dims_metrics_exception_slot(int exception_type, int *kind, int *severity); /* The names the exposition writer prints for each index. */ const char *dims_metrics_endpoint_name(int index); @@ -111,6 +148,13 @@ const char *dims_metrics_outcome_name(int index); const char *dims_metrics_code_name(int index); const char *dims_metrics_origin_code_name(int index); const char *dims_metrics_format_name(int index); +const char *dims_metrics_curl_code_name(int index); +const char *dims_metrics_operation_name(int index); +const char *dims_metrics_exception_kind_name(int index); +const char *dims_metrics_exception_severity_name(int index); +const char *dims_metrics_fetch_result_name(int index); +const char *dims_metrics_net_reason_name(int index); +const char *dims_metrics_sig_result_name(int index); /* The bucket a value belongs in, counting the +Inf bucket as spec->bounds. */ int dims_metrics_bucket_index(const dims_bucket_spec *spec, double value); @@ -119,6 +163,60 @@ int dims_metrics_bucket_index(const dims_bucket_spec *spec, double value); void dims_metrics_observe(dims_histogram_rec *h, const dims_bucket_spec *spec, apr_uint64_t value); +/* Why a source fetch ended, as a slot in the fetch table. */ +typedef enum { + DIMS_FETCH_OK = 0, + DIMS_FETCH_TIMEOUT, + DIMS_FETCH_TRANSPORT_ERROR, + DIMS_FETCH_REFUSED, + DIMS_FETCH_HTTP_ERROR +} dims_fetch_result; + +/* Counts one source fetch. curl_code counts too when the result is an error. */ +void dims_metrics_fetch(dims_fetch_result result, int curl_code); + +/* How a signature check ended, as a slot in the signature table. */ +typedef enum { + DIMS_SIG_OK = 0, + DIMS_SIG_MISMATCH, + DIMS_SIG_EXPIRED, + DIMS_SIG_TOO_FAR_FUTURE, + DIMS_SIG_MISSING_KEY, + DIMS_SIG_BAD_CLIENT +} dims_sig_result; + +/* Counts one signature check. */ +void dims_metrics_signature(int endpoint, dims_sig_result result); + +/* Counts one eurl decryption. ok is nonzero when it succeeded. */ +void dims_metrics_eurl(int ok); + +/* Counts one network guard result, from a dims_net_result. */ +void dims_metrics_netguard(int reason); + +/* Counts one allowlist check under a dims_allowlist_mode. */ +void dims_metrics_allowlist(int mode, int allowed); + +/* Counts one operation call and its duration. */ +void dims_metrics_operation(int op_index, int from_default, apr_time_t began, + int failed); + +/* Counts one ImageMagick exception, from an ExceptionType. */ +void dims_metrics_exception(int exception_type); + +/* Counts one overlay cache lookup. result is a slot: hit, miss, expired. */ +void dims_metrics_overlay_lookup(int result); + +/* + * Counts one error image. source is 0 for a drawn image, 1 for a fetched one, + * and 2 for a server with neither. failed is nonzero when the error image + * itself failed. + */ +void dims_metrics_error_image(int source, int failed); + +/* Counts one overlay cache eviction. */ +void dims_metrics_overlay_eviction(void); + /* * Counts a request and records its duration when it ends. Registers a pool * cleanup, so every return path in the handler reaches it exactly once. diff --git a/src/metrics_report.c b/src/metrics_report.c index 1a6b26c..1528116 100644 --- a/src/metrics_report.c +++ b/src/metrics_report.c @@ -336,6 +336,138 @@ write_build(request_rec *r, const dims_config_rec *config) escape(r->pool, curl_version())); } +/* The security, operation, and cache families. */ +static void +write_detail(request_rec *r, const dims_metrics_rec *m) +{ + static const char *const mode_name[3] = { "skip", "log", "enforce" }; + static const char *const overlay_name[3] = { "hit", "miss", "expired" }; + static const char *const error_source[3] = { "drawn", "fetched", "none" }; + char labels[96]; + int i, j; + + head(r, "dims_source_fetch_total", "Source fetches by result.", "counter"); + for (i = 0; i < DIMS_FETCH_RESULT_COUNT; i++) { + ap_rprintf(r, "dims_source_fetch_total{result=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_fetch_result_name(i), read64(&m->fetch_results[i])); + } + + head(r, "dims_source_fetch_errors_total", + "Source fetch failures by libcurl code.", "counter"); + for (i = 0; i < DIMS_CURL_CODE_COUNT; i++) { + ap_rprintf(r, "dims_source_fetch_errors_total{code=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_curl_code_name(i), read64(&m->fetch_errors[i])); + } + + head(r, "dims_netguard_refusals_total", + "Fetches the network guard refused, by reason.", "counter"); + for (i = 0; i < DIMS_NET_REASON_COUNT; i++) { + ap_rprintf(r, "dims_netguard_refusals_total{reason=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_net_reason_name(i), read64(&m->netguard[i])); + } + + head(r, "dims_allowlist_checks_total", + "Allowlist checks by mode and result.", "counter"); + for (i = 0; i < 3; i++) { + ap_rprintf(r, "dims_allowlist_checks_total{mode=\"%s\"," + "result=\"allowed\"} %" APR_UINT64_T_FMT "\n", + mode_name[i], read64(&m->allowlist[i][0])); + ap_rprintf(r, "dims_allowlist_checks_total{mode=\"%s\"," + "result=\"refused\"} %" APR_UINT64_T_FMT "\n", + mode_name[i], read64(&m->allowlist[i][1])); + } + + head(r, "dims_signature_checks_total", + "Signature checks by endpoint and result.", "counter"); + for (i = 0; i < DIMS_ENDPOINT_COUNT; i++) { + for (j = 0; j < DIMS_SIG_RESULT_COUNT; j++) { + ap_rprintf(r, "dims_signature_checks_total{endpoint=\"%s\"," + "result=\"%s\"} %" APR_UINT64_T_FMT "\n", + dims_metrics_endpoint_name(i), + dims_metrics_sig_result_name(j), + read64(&m->signature[i][j])); + } + } + + head(r, "dims_eurl_decrypt_total", "eurl decryptions by result.", + "counter"); + ap_rprintf(r, "dims_eurl_decrypt_total{result=\"ok\"} " + "%" APR_UINT64_T_FMT "\n", read64(&m->eurl[0])); + ap_rprintf(r, "dims_eurl_decrypt_total{result=\"failed\"} " + "%" APR_UINT64_T_FMT "\n", read64(&m->eurl[1])); + + /* One call, not one request. A multi-frame source runs the command loop + * once per frame, and strip and format also run without a command. */ + head(r, "dims_operations_total", "Operation functions called.", "counter"); + for (i = 0; i < DIMS_OP_COUNT; i++) { + ap_rprintf(r, "dims_operations_total{operation=\"%s\"," + "trigger=\"request\"} %" APR_UINT64_T_FMT "\n", + dims_metrics_operation_name(i), read64(&m->operations[i][0])); + ap_rprintf(r, "dims_operations_total{operation=\"%s\"," + "trigger=\"default\"} %" APR_UINT64_T_FMT "\n", + dims_metrics_operation_name(i), read64(&m->operations[i][1])); + } + + head(r, "dims_operation_failures_total", + "Operation functions that reported a failure.", "counter"); + for (i = 0; i < DIMS_OP_COUNT; i++) { + ap_rprintf(r, "dims_operation_failures_total{operation=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + dims_metrics_operation_name(i), + read64(&m->operation_failures[i])); + } + + head(r, "dims_operation_duration_seconds", "Time in one operation call.", + "histogram"); + for (i = 0; i < DIMS_OP_COUNT; i++) { + apr_snprintf(labels, sizeof(labels), "operation=\"%s\"", + dims_metrics_operation_name(i)); + histogram(r, "dims_operation_duration_seconds", + &m->operation_duration[i], &dims_duration_buckets, 1, labels); + } + + head(r, "dims_imagemagick_exceptions_total", + "ImageMagick exceptions by kind and severity.", "counter"); + for (i = 0; i < DIMS_EXC_KIND_COUNT; i++) { + for (j = 0; j < DIMS_EXC_SEVERITY_COUNT; j++) { + ap_rprintf(r, "dims_imagemagick_exceptions_total{kind=\"%s\"," + "severity=\"%s\"} %" APR_UINT64_T_FMT "\n", + dims_metrics_exception_kind_name(i), + dims_metrics_exception_severity_name(j), + read64(&m->exceptions[i][j])); + } + } + + head(r, "dims_overlay_cache_lookups_total", + "Overlay cache lookups by result.", "counter"); + for (i = 0; i < 3; i++) { + ap_rprintf(r, "dims_overlay_cache_lookups_total{result=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + overlay_name[i], read64(&m->overlay_lookups[i])); + } + + head(r, "dims_overlay_cache_evictions_total", + "Overlays dropped to make room.", "counter"); + ap_rprintf(r, "dims_overlay_cache_evictions_total %" APR_UINT64_T_FMT "\n", + read64(&m->overlay_evictions)); + + head(r, "dims_error_images_total", "Error images sent, by source.", + "counter"); + for (i = 0; i < 3; i++) { + ap_rprintf(r, "dims_error_images_total{source=\"%s\"} " + "%" APR_UINT64_T_FMT "\n", + error_source[i], read64(&m->error_images[i])); + } + + head(r, "dims_error_image_failures_total", + "Failed requests whose error image also failed.", "counter"); + ap_rprintf(r, "dims_error_image_failures_total %" APR_UINT64_T_FMT "\n", + read64(&m->error_image_failures)); +} + static void write_metrics(request_rec *r, const dims_config_rec *config) { @@ -435,6 +567,7 @@ write_metrics(request_rec *r, const dims_config_rec *config) histogram(r, "dims_source_frames", &m->source_frames, &dims_frame_buckets, 0, ""); + write_detail(r, m); write_process(r, m); write_httpd(r); write_build(r, config); diff --git a/src/mod_dims.c b/src/mod_dims.c index 2b08991..14c456a 100644 --- a/src/mod_dims.c +++ b/src/mod_dims.c @@ -205,6 +205,8 @@ dims_fetch_remote_image(dims_request_rec *d, const char *url) d->status = DIMS_NETWORK_REFUSED; d->fetch_http_status = HTTP_BAD_REQUEST; + dims_metrics_fetch(DIMS_FETCH_REFUSED, 0); + return 1; } @@ -237,8 +239,22 @@ dims_fetch_remote_image(dims_request_rec *d, const char *url) if (d->net_refusal != DIMS_NET_OK) { d->status = DIMS_NETWORK_REFUSED; d->fetch_http_status = HTTP_BAD_REQUEST; + + /* The socket callback refused it, so the guard has not + * counted this one. */ + if (code != CURLE_TOO_MANY_REDIRECTS) { + dims_metrics_netguard(d->net_refusal); + } } + /* The libcurl code names what went wrong, where the outcome only + * says the fetch failed. */ + dims_metrics_fetch( + (d->net_refusal != DIMS_NET_OK) ? DIMS_FETCH_REFUSED + : (code == CURLE_OPERATION_TIMEDOUT) + ? DIMS_FETCH_TIMEOUT : DIMS_FETCH_TRANSPORT_ERROR, + code); + d->download_time = (apr_time_now() - start_time) / 1000; return 1; @@ -256,6 +272,8 @@ dims_fetch_remote_image(dims_request_rec *d, const char *url) d->status = DIMS_FILE_NOT_FOUND; } + dims_metrics_fetch(DIMS_FETCH_HTTP_ERROR, 0); + if(image_data.data) { free(image_data.data); } @@ -263,6 +281,8 @@ dims_fetch_remote_image(dims_request_rec *d, const char *url) return 1; } + dims_metrics_fetch(DIMS_FETCH_OK, 0); + /* ImageMagick's SVG renderer reads a local file named by an * href, so refuse a source that references an external resource before * the renderer sees it. */ @@ -602,6 +622,7 @@ dims_free_request(dims_request_rec *d) msg = MagickGetException(d->wand, &type); if (type != UndefinedException && msg) { + dims_metrics_exception(type); ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, d->r, "Imagemagick error, '%s', on request: %s ", msg, d->r->uri); } @@ -723,17 +744,23 @@ dims_cleanup(dims_request_rec *d, const char *err_msg, int status) if (dims_draw_error_image(d)) { dims_strip_error_image(d); + dims_metrics_error_image(0, 0); return dims_send_image(d); } + dims_metrics_error_image(0, 1); dims_free_request(d); } else if (d->no_image_url) { d->wand = NewMagickWand(); if (!dims_fetch_remote_image(d, NULL)) { dims_strip_error_image(d); + dims_metrics_error_image(1, 0); return dims_send_image(d); } + dims_metrics_error_image(1, 1); dims_free_request(d); + } else { + dims_metrics_error_image(2, 0); } /* With no error image to send, the status is all the caller gets. This is @@ -874,12 +901,21 @@ dims_run_commands(dims_request_rec *d, apr_hash_t *ops, int *exc_strip_cmd, func = apr_hash_get(ops, command, APR_HASH_KEY_STRING); if (func != NULL) { apr_status_t code; + apr_time_t began; ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "Executing command %s(%s), on request %s", command, args, d->r->uri); - if ((code = func(d, args, err)) != DIMS_SUCCESS) { + began = apr_time_now(); + code = func(d, args, err); + + /* One call, not one request. A multi-frame source runs this loop + * once per frame. */ + dims_metrics_operation(dims_metrics_operation_index(command), 0, + began, code != DIMS_SUCCESS); + + if (code != DIMS_SUCCESS) { return code; } } @@ -1050,8 +1086,15 @@ dims_process_image(dims_request_rec *d) if (use_default) { const char *err = NULL; apr_status_t code; + apr_time_t began = apr_time_now(); + + code = dims_format_operation(d, + d->config->default_output_format, &err); + + dims_metrics_operation(dims_metrics_operation_index("format"), + 1, began, code != DIMS_SUCCESS); - if((code = dims_format_operation(d, d->config->default_output_format, &err)) != DIMS_SUCCESS) { + if (code != DIMS_SUCCESS) { return dims_cleanup(d, err, code); } } @@ -1066,11 +1109,18 @@ dims_process_image(dims_request_rec *d) if(strip_func != NULL) { const char *err = NULL; apr_status_t code; + apr_time_t began; ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, d->r, "Executing default strip command, on request %s", d->r->uri); - if((code = strip_func(d, NULL, &err)) != DIMS_SUCCESS) { + began = apr_time_now(); + code = strip_func(d, NULL, &err); + + dims_metrics_operation(dims_metrics_operation_index("strip"), 1, + began, code != DIMS_SUCCESS); + + if (code != DIMS_SUCCESS) { return dims_cleanup(d, err, code); } } diff --git a/src/netguard.c b/src/netguard.c index e85d78b..2fee6ca 100644 --- a/src/netguard.c +++ b/src/netguard.c @@ -6,6 +6,7 @@ */ #include "netguard.h" +#include "metrics.h" #include #include @@ -230,8 +231,8 @@ dims_host_allowed(apr_table_t *whitelist, const char *hostname) return found; } -dims_net_result -dims_validate_image_url(dims_request_rec *d, const char *url, dims_allowlist_mode mode) +static dims_net_result +validate_url(dims_request_rec *d, const char *url, dims_allowlist_mode mode) { apr_uri_t uri; @@ -249,23 +250,41 @@ dims_validate_image_url(dims_request_rec *d, const char *url, dims_allowlist_mod return DIMS_NET_BAD_URL; } - if (mode != DIMS_ALLOWLIST_SKIP && - !dims_host_allowed(d->config->whitelist, uri.hostname)) { - if (mode == DIMS_ALLOWLIST_ENFORCE) { - return DIMS_NET_HOST_NOT_ALLOWED; - } + if (mode != DIMS_ALLOWLIST_SKIP) { + int allowed = dims_host_allowed(d->config->whitelist, uri.hostname); - /* Report what enforcing would cost, so an operator can fill the - * allowlist from the log before setting the directive. */ - ap_log_rerror(APLOG_MARK, APLOG_WARNING, 0, d->r, - "DimsAllowlistSigned enforce would refuse %s: %s, " - "on request: %s", uri.hostname, - dims_net_reason(DIMS_NET_HOST_NOT_ALLOWED), d->r->uri); + dims_metrics_allowlist(mode, allowed); + + if (!allowed) { + if (mode == DIMS_ALLOWLIST_ENFORCE) { + return DIMS_NET_HOST_NOT_ALLOWED; + } + + /* Report what enforcing would cost, so an operator can fill the + * allowlist from the log before setting the directive. */ + ap_log_rerror(APLOG_MARK, APLOG_WARNING, 0, d->r, + "DimsAllowlistSigned enforce would refuse %s: %s, " + "on request: %s", uri.hostname, + dims_net_reason(DIMS_NET_HOST_NOT_ALLOWED), + d->r->uri); + } } return DIMS_NET_OK; } +/* Records the result, so every refusal counts once whatever refused it. */ +dims_net_result +dims_validate_image_url(dims_request_rec *d, const char *url, + dims_allowlist_mode mode) +{ + dims_net_result result = validate_url(d, url, mode); + + dims_metrics_netguard(result); + + return result; +} + /* * Runs once per connection, after the name resolves and before the socket * opens. A name that resolves to a refused address is refused whatever it is diff --git a/src/overlay_cache.c b/src/overlay_cache.c index c80660d..ad2b851 100644 --- a/src/overlay_cache.c +++ b/src/overlay_cache.c @@ -6,6 +6,7 @@ */ #include "overlay_cache.h" +#include "metrics.h" #include #include @@ -196,6 +197,7 @@ dims_overlay_memcache_get(const char *url) { dims_overlay_memcache *cache = overlay_memcache; MagickWand *clone = NULL; + int expired = 0; int i; if (cache == NULL || url == NULL) { @@ -219,6 +221,7 @@ dims_overlay_memcache_get(const char *url) free(entry->url); entry->url = NULL; entry->wand = NULL; + expired = 1; break; } @@ -232,6 +235,10 @@ dims_overlay_memcache_get(const char *url) apr_thread_mutex_unlock(cache->mutex); + /* An entry past its age reports separately from a name the cache never + * held, because the two point at different settings. */ + dims_metrics_overlay_lookup(expired ? 2 : (clone != NULL) ? 0 : 1); + return clone; } @@ -283,9 +290,11 @@ dims_overlay_memcache_put(const char *url, MagickWand *wand) return; } + /* The slot held another overlay, so storing this one drops it. */ if (slot->url != NULL) { DestroyMagickWand(slot->wand); free(slot->url); + dims_metrics_overlay_eviction(); } slot->url = key; diff --git a/test/http/test_metrics.c b/test/http/test_metrics.c index 89eab16..361ba13 100644 --- a/test/http/test_metrics.c +++ b/test/http/test_metrics.c @@ -406,6 +406,100 @@ test_metrics_reports_the_build(void) dims_response_free(response); } +/* + * The allowlist check in the handler refuses a /dims3/ request before the + * fetch, so it reports there. The guard runs its own check at fetch time and + * reports every refusal it makes. + */ +static void +test_metrics_counts_the_guard(void) +{ + dims_response *before = scrape(); + double was = dims_prom_value(before, "dims_allowlist_checks_total{" + "mode=\"enforce\",result=\"refused\"}"); + dims_response *after; + + dims_response_free(dims_get("/dims3/TEST/resize/40x40/" + "?url=http://notallowed:8080/grid.png")); + + after = scrape(); + CHECK(dims_prom_value(after, "dims_allowlist_checks_total{" + "mode=\"enforce\",result=\"refused\"}") >= was + 1, + "the allowlist counter moved from %g", was); + CHECK(dims_prom_value(after, "dims_allowlist_checks_total{" + "mode=\"enforce\",result=\"allowed\"}") >= 1, + "an allowed host counts too"); + CHECK(dims_prom_value(after, "dims_source_fetch_total{result=\"refused\"}") + >= 1, + "the guard refuses a fetch of its own"); + + dims_response_free(before); + dims_response_free(after); +} + +/* A signed request that verifies, and one that does not. */ +static void +test_metrics_counts_signatures(void) +{ + dims_response *after; + + dims_response_free(dims_request_ops("resize/40x40", "grid.png")); + + after = scrape(); + CHECK(dims_prom_value(after, "dims_signature_checks_total{" + "endpoint=\"dims4\",result=\"ok\"}") >= 1, + "a signature verified"); + + dims_response_free(after); +} + +/* + * A command counts under its own name. strip runs without a command, so it + * counts under the default trigger. + */ +static void +test_metrics_counts_operations(void) +{ + dims_response *before = scrape(); + double was = dims_prom_value(before, + "dims_operations_total{operation=\"crop\",trigger=\"request\"}"); + dims_response *after; + + dims_response_free(dims_request_ops("crop/40x40+0+0", "grid.png")); + + after = scrape(); + CHECK(dims_prom_value(after, + "dims_operations_total{operation=\"crop\",trigger=\"request\"}") + >= was + 1, + "the crop counter moved from %g", was); + CHECK(dims_prom_value(after, + "dims_operations_total{operation=\"strip\",trigger=\"default\"}") + >= 1, + "strip runs without a command"); + CHECK(dims_prom_value(after, "dims_operation_duration_seconds_count{" + "operation=\"crop\"}") >= 1, + "the crop duration histogram"); + + dims_response_free(after); +} + +/* A failed request sends the error image this server draws. */ +static void +test_metrics_counts_the_error_image(void) +{ + dims_response *after; + + dims_response_free(dims_request_ops("resize/40x40", "missing.png")); + + after = scrape(); + CHECK(dims_prom_value(after, "dims_error_images_total{source=\"fetched\"}") + + dims_prom_value(after, + "dims_error_images_total{source=\"drawn\"}") >= 1, + "an error image was sent"); + + dims_response_free(after); +} + const dims_test dims_tests_metrics[] = { { "TestMetricsContentType", test_metrics_content_type, NULL }, { "TestMetricsFormat", test_metrics_format, NULL }, @@ -421,6 +515,11 @@ const dims_test dims_tests_metrics[] = { { "TestMetricsReportsTheWorkerPool", test_metrics_reports_the_worker_pool, NULL }, { "TestMetricsReportsTheBuild", test_metrics_reports_the_build, NULL }, + { "TestMetricsCountsTheGuard", test_metrics_counts_the_guard, NULL }, + { "TestMetricsCountsSignatures", test_metrics_counts_signatures, NULL }, + { "TestMetricsCountsOperations", test_metrics_counts_operations, NULL }, + { "TestMetricsCountsTheErrorImage", test_metrics_counts_the_error_image, + NULL }, { "TestMetricsDisabled", test_metrics_disabled, NULL }, DIMS_TEST_END }; From 1f4599d997ae75480dcc2b3cf241d5f9b90123e6 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 14:52:59 -0400 Subject: [PATCH 13/16] Document the guard, signature, operation, and cache metrics Fourteen families and their labels join the endpoint page. --- docs/docs/endpoints/metrics.md | 44 ++++++++++++++++++++++++++++++++++ 1 file changed, 44 insertions(+) diff --git a/docs/docs/endpoints/metrics.md b/docs/docs/endpoints/metrics.md index a2f2b82..26f84a5 100644 --- a/docs/docs/endpoints/metrics.md +++ b/docs/docs/endpoints/metrics.md @@ -54,6 +54,20 @@ dims_request_duration_seconds_count{endpoint="dims5"} 18427 | `dims_output_bytes` | histogram | | | `dims_output_bytes_total` | counter | | | `dims_output_format_total` | counter | `format` | +| `dims_source_fetch_total` | counter | `result` | +| `dims_source_fetch_errors_total` | counter | `code` | +| `dims_netguard_refusals_total` | counter | `reason` | +| `dims_allowlist_checks_total` | counter | `mode`, `result` | +| `dims_signature_checks_total` | counter | `endpoint`, `result` | +| `dims_eurl_decrypt_total` | counter | `result` | +| `dims_operations_total` | counter | `operation`, `trigger` | +| `dims_operation_failures_total` | counter | `operation` | +| `dims_operation_duration_seconds` | histogram | `operation` | +| `dims_imagemagick_exceptions_total` | counter | `kind`, `severity` | +| `dims_overlay_cache_lookups_total` | counter | `result` | +| `dims_overlay_cache_evictions_total` | counter | | +| `dims_error_images_total` | counter | `source` | +| `dims_error_image_failures_total` | counter | | | `dims_imagemagick_resource_bytes` | gauge | `resource` | | `dims_imagemagick_resource_max_bytes` | gauge | `resource` | | `dims_imagemagick_resource_limit_bytes` | gauge | `resource` | @@ -84,6 +98,36 @@ status the origin returned. `resource` holds `area`, `memory`, `map`, or `disk`. +`result` on `dims_source_fetch_total` holds `ok`, `timeout`, +`transport_error`, `refused`, or `http_error`. `code` on +`dims_source_fetch_errors_total` holds a libcurl name such as +`couldnt_resolve_host` or `ssl_connect_error`, and `other` for the rest. + +`reason` holds `bad_scheme`, `bad_url`, `reserved_address`, +`private_address`, `host_not_allowed`, or `too_many_redirects`. + +`mode` holds `skip`, `log`, or `enforce`. Under +[`DimsAllowlistSigned`](/configuration/image-sources) `log` the module records +what enforcing would refuse and serves the request, so +`dims_allowlist_checks_total{mode="log",result="refused"}` is the number to +watch before setting `enforce`. + +`result` on a signature holds `ok`, `mismatch`, `expired`, `too_far_future`, +`missing_key`, or `bad_client`. + +`operation` holds one of the seventeen command names. `trigger` holds +`request` or `default`. `strip` runs when the command list holds none, and +`format` runs under [`DimsDefaultOutputFormat`](/configuration/output), so +both report `default`. + +`kind` holds an ImageMagick exception kind such as `resource_limit`, +`corrupt_image`, or `policy`. `severity` holds `warning`, `error`, or +`fatal`. + +`source` on an error image holds `drawn` for +[`DimsErrorBackground`](/configuration/cache-control), `fetched` for +[`DimsDefaultImageURL`](/configuration/cache-control), or `none`. + ## The whole server Every metric describes the server, with no `client` label. The client id is a From 9f8b5655f0dcc59e92633115edacd2f93aa88b9e Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 15:08:31 -0400 Subject: [PATCH 14/16] Watch a soak run in Grafana test/endurance/observe holds a Prometheus and a Grafana that join the soak network and scrape the server on port 8001. up.sh starts them and prints the dashboard address. Grafana listens on every interface, so another machine reaches it. The dashboard has six sections: the overview, the request path, the source fetch, the image processing, the guard and the signature, and the resources. run.sh sets DIMS_METRICS_ENABLED=on, so a run publishes its metrics. --- test/endurance/observe/README.md | 60 + test/endurance/observe/compose.yaml | 41 + .../observe/grafana/dashboards/mod_dims.json | 1884 +++++++++++++++++ .../observe/grafana/dashboards/provider.yml | 7 + .../grafana/datasources/prometheus.yml | 9 + test/endurance/observe/prometheus.yml | 10 + test/endurance/observe/up.sh | 26 + test/endurance/run.sh | 2 + 8 files changed, 2039 insertions(+) create mode 100644 test/endurance/observe/README.md create mode 100644 test/endurance/observe/compose.yaml create mode 100644 test/endurance/observe/grafana/dashboards/mod_dims.json create mode 100644 test/endurance/observe/grafana/dashboards/provider.yml create mode 100644 test/endurance/observe/grafana/datasources/prometheus.yml create mode 100644 test/endurance/observe/prometheus.yml create mode 100755 test/endurance/observe/up.sh diff --git a/test/endurance/observe/README.md b/test/endurance/observe/README.md new file mode 100644 index 0000000..fdea57d --- /dev/null +++ b/test/endurance/observe/README.md @@ -0,0 +1,60 @@ +# Watching a soak + +Prometheus scrapes the soak server and Grafana draws it. + +``` +bash test/endurance/run.sh & +bash test/endurance/observe/up.sh +``` + +`up.sh` prints the dashboard address. Grafana listens on every interface at +port 3000, so another machine on the network reaches it. + +The soak creates `dims-soak-net` and gives its server the alias `dims`, so +this stack joins that network and scrapes `dims:8001`. Start the soak first. + +`run.sh` sets `DIMS_METRICS_ENABLED=on`, so a run publishes its metrics with +no further setting. + +## The dashboard + +Six sections, from the top. + +**Overview** reports the request rate, the error ratio, the p99 latency, +requests in flight, resident memory, and ready workers. + +**Request path** breaks the rate down by outcome, by status code, and by +endpoint, with the latency quantiles beside them. + +**Source fetch** separates a slow origin from a broken one. The libcurl code +panel tells DNS from TLS from a reset connection, and the origin status panel +reports what the origin returned. + +**Image processing** answers which command spends the time. The mean seconds +per call panel is the one that names an expensive operation, because a +watermark fetches an overlay and a resize does not. The exception panel splits +ImageMagick failures by kind: `resource_limit` is the pixel cache reaching a +ceiling, `corrupt_image` is a bad source, and `policy` is `policy.xml` +refusing a coder. + +**Guard and signature** reports what the network guard refused and why, the +allowlist checks by mode, and the signature results. Under +`DimsAllowlistSigned log` the refused line is what `enforce` would reject. + +**Resources** puts ImageMagick use beside its limit, so the ratio is visible. +The process memory panel is the one a soak watches for a trend. + +## Stopping it + +``` +docker compose -f test/endurance/observe/compose.yaml down +``` + +Prometheus keeps 24 hours and stores it in the container, so removing the +container drops the history. + +## Anonymous access + +Grafana runs with the login form off and anonymous viewing on. It reads a +local soak and holds nothing worth protecting. A deployment that reaches +further sets `GF_AUTH_ANONYMOUS_ENABLED=false` in `compose.yaml`. diff --git a/test/endurance/observe/compose.yaml b/test/endurance/observe/compose.yaml new file mode 100644 index 0000000..0e8c759 --- /dev/null +++ b/test/endurance/observe/compose.yaml @@ -0,0 +1,41 @@ +# Prometheus and Grafana for watching a soak run. +# +# bash test/endurance/observe/up.sh +# +# The soak creates dims-soak-net and gives its server the alias "dims", so +# Prometheus reaches it at dims:8001. Start the soak first. +name: dims-observe + +services: + prometheus: + image: prom/prometheus:v3.1.0 + command: + - --config.file=/etc/prometheus/prometheus.yml + - --storage.tsdb.retention.time=24h + volumes: + - ./prometheus.yml:/etc/prometheus/prometheus.yml:ro + networks: [soak] + restart: unless-stopped + + grafana: + image: grafana/grafana:11.5.1 + ports: + # Every interface, so the dashboard is reachable from another machine. + - "0.0.0.0:3000:3000" + environment: + GF_AUTH_ANONYMOUS_ENABLED: "true" + GF_AUTH_ANONYMOUS_ORG_ROLE: Viewer + GF_AUTH_DISABLE_LOGIN_FORM: "true" + GF_SECURITY_ALLOW_EMBEDDING: "true" + GF_USERS_DEFAULT_THEME: dark + volumes: + - ./grafana/datasources:/etc/grafana/provisioning/datasources:ro + - ./grafana/dashboards:/etc/grafana/provisioning/dashboards:ro + networks: [soak] + depends_on: [prometheus] + restart: unless-stopped + +networks: + soak: + name: dims-soak-net + external: true diff --git a/test/endurance/observe/grafana/dashboards/mod_dims.json b/test/endurance/observe/grafana/dashboards/mod_dims.json new file mode 100644 index 0000000..c8c8da5 --- /dev/null +++ b/test/endurance/observe/grafana/dashboards/mod_dims.json @@ -0,0 +1,1884 @@ +{ + "uid": "mod-dims-soak", + "title": "mod_dims", + "tags": [ + "mod_dims" + ], + "timezone": "browser", + "schemaVersion": 39, + "version": 1, + "refresh": "5s", + "time": { + "from": "now-15m", + "to": "now" + }, + "editable": true, + "graphTooltip": 1, + "panels": [ + { + "id": 101, + "title": "Overview", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 0, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 102, + "title": "Requests / sec", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "sum(rate(dims_requests_total[1m]))", + "legendFormat": "total", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 103, + "title": "Error ratio", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 4, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "sum(rate(dims_requests_total{outcome!=\"success\"}[1m])) / clamp_min(sum(rate(dims_requests_total[1m])), 0.001)", + "legendFormat": "errors", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "percentunit", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 104, + "title": "p99 latency", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 8, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "histogram_quantile(0.99, sum by (le) (rate(dims_request_duration_seconds_bucket[1m])))", + "legendFormat": "p99", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "s", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 105, + "title": "In flight", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "sum(dims_requests_in_flight)", + "legendFormat": "in flight", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "short", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 106, + "title": "Resident memory", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 16, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "dims_process_resident_bytes", + "legendFormat": "resident", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "bytes", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 107, + "title": "Workers ready", + "type": "stat", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 20, + "y": 1, + "w": 4, + "h": 5 + }, + "targets": [ + { + "expr": "dims_httpd_workers{state=\"ready\"}", + "legendFormat": "ready", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "short", + "custom": {}, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "textMode": "auto" + } + }, + { + "id": 108, + "title": "Request path", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 6, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 109, + "title": "Requests by outcome", + "type": "timeseries", + "description": "Every request counts once, under the endpoint it arrived on.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 7, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (outcome) (rate(dims_requests_total[1m]))", + "legendFormat": "{{outcome}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 110, + "title": "Responses by status", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 7, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (code) (rate(dims_responses_total[1m]))", + "legendFormat": "{{code}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 111, + "title": "Latency quantiles", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 15, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "histogram_quantile(0.50, sum by (le) (rate(dims_request_duration_seconds_bucket[1m])))", + "legendFormat": "p50", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "histogram_quantile(0.90, sum by (le) (rate(dims_request_duration_seconds_bucket[1m])))", + "legendFormat": "p90", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "histogram_quantile(0.99, sum by (le) (rate(dims_request_duration_seconds_bucket[1m])))", + "legendFormat": "p99", + "refId": "C", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "s", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 112, + "title": "Requests by endpoint", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 15, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (endpoint) (rate(dims_requests_total[1m]))", + "legendFormat": "{{endpoint}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 113, + "title": "Source fetch", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 23, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 114, + "title": "Fetch result", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 24, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (result) (rate(dims_source_fetch_total[1m]))", + "legendFormat": "{{result}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 115, + "title": "Fetch errors by libcurl code", + "type": "timeseries", + "description": "Separates DNS from TLS from a slow origin.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 8, + "y": 24, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (code) (rate(dims_source_fetch_errors_total[1m])) > 0", + "legendFormat": "{{code}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 116, + "title": "Origin status", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 16, + "y": 24, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (code) (rate(dims_origin_responses_total[1m])) > 0", + "legendFormat": "{{code}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 117, + "title": "Origin throughput", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 31, + "w": 12, + "h": 7 + }, + "targets": [ + { + "expr": "rate(dims_source_bytes_total[1m])", + "legendFormat": "source in", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "rate(dims_output_bytes_total[1m])", + "legendFormat": "output out", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "Bps", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 118, + "title": "Source format", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 31, + "w": 12, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (format) (rate(dims_source_format_total[1m])) > 0", + "legendFormat": "{{format}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 119, + "title": "Image processing", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 38, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 120, + "title": "Time by operation", + "type": "timeseries", + "description": "Which command spends the service's time.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 39, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "topk(8, sum by (operation) (rate(dims_operation_duration_seconds_sum[1m])))", + "legendFormat": "{{operation}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "s", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 121, + "title": "Mean seconds per operation call", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 39, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (operation) (rate(dims_operation_duration_seconds_sum[1m])) / clamp_min(sum by (operation) (rate(dims_operation_duration_seconds_count[1m])), 0.001) > 0", + "legendFormat": "{{operation}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "s", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 122, + "title": "Operation calls", + "type": "timeseries", + "description": "One call, not one request. A multi-frame source runs the loop per frame.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 47, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (operation) (rate(dims_operations_total[1m])) > 0", + "legendFormat": "{{operation}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "ops", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 123, + "title": "ImageMagick exceptions", + "type": "timeseries", + "description": "resource_limit is the pixel cache. corrupt_image is a bad source. policy is policy.xml.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 47, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "sum by (kind) (rate(dims_imagemagick_exceptions_total[1m])) > 0", + "legendFormat": "{{kind}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "ops", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 124, + "title": "Source frames", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 55, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "histogram_quantile(0.99, sum by (le) (rate(dims_source_frames_bucket[1m])))", + "legendFormat": "p99 frames", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "histogram_quantile(0.50, sum by (le) (rate(dims_source_frames_bucket[1m])))", + "legendFormat": "p50 frames", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "short", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 125, + "title": "Image sizes", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 8, + "y": 55, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "histogram_quantile(0.99, sum by (le) (rate(dims_source_bytes_bucket[1m])))", + "legendFormat": "p99 source", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "histogram_quantile(0.99, sum by (le) (rate(dims_output_bytes_bucket[1m])))", + "legendFormat": "p99 output", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "bytes", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 126, + "title": "ImageMagick time share", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 16, + "y": 55, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "rate(dims_imagemagick_duration_seconds_sum[1m])", + "legendFormat": "imagemagick", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "rate(dims_source_fetch_duration_seconds_sum[1m])", + "legendFormat": "source fetch", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "s", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 127, + "title": "Guard and signature", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 62, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 128, + "title": "Network guard refusals", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 63, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (reason) (rate(dims_netguard_refusals_total[1m])) > 0", + "legendFormat": "{{reason}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 129, + "title": "Allowlist checks", + "type": "timeseries", + "description": "Under log, refused is what enforce would reject.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 8, + "y": 63, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (mode, result) (rate(dims_allowlist_checks_total[1m])) > 0", + "legendFormat": "{{mode}} {{result}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 130, + "title": "Signature checks", + "type": "timeseries", + "description": "mismatch means a stale secret. expired means clock drift.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 16, + "y": 63, + "w": 8, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (result) (rate(dims_signature_checks_total[1m])) > 0", + "legendFormat": "{{result}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "reqps", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 131, + "title": "Resources", + "type": "row", + "collapsed": false, + "gridPos": { + "x": 0, + "y": 70, + "w": 24, + "h": 1 + }, + "panels": [] + }, + { + "id": 132, + "title": "ImageMagick resource use against its limit", + "type": "timeseries", + "description": "Disk rising while memory sits at its ceiling means the pixel cache spilled.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 71, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "dims_imagemagick_resource_bytes{resource=~\"memory|map|disk\"}", + "legendFormat": "{{resource}} used", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "dims_imagemagick_resource_limit_bytes{resource=~\"memory|map|disk\"}", + "legendFormat": "{{resource}} limit", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "bytes", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 133, + "title": "Process memory", + "type": "timeseries", + "description": "The soak watches this line for a trend.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 71, + "w": 12, + "h": 8 + }, + "targets": [ + { + "expr": "dims_process_resident_bytes", + "legendFormat": "resident sum", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "dims_process_resident_max_bytes", + "legendFormat": "widest worker", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "dims_process_virtual_bytes", + "legendFormat": "virtual sum", + "refId": "C", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "bytes", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 134, + "title": "httpd workers by state", + "type": "timeseries", + "description": "Ready near zero while in flight climbs means the pool is full.", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 0, + "y": 79, + "w": 12, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (state) (dims_httpd_workers{state!=\"dead\"})", + "legendFormat": "{{state}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "short", + "custom": { + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "normal", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + }, + { + "id": 135, + "title": "Overlay cache and error images", + "type": "timeseries", + "description": "", + "datasource": { + "type": "prometheus", + "uid": "PROM" + }, + "gridPos": { + "x": 12, + "y": 79, + "w": 12, + "h": 7 + }, + "targets": [ + { + "expr": "sum by (result) (rate(dims_overlay_cache_lookups_total[1m])) > 0", + "legendFormat": "overlay {{result}}", + "refId": "A", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + }, + { + "expr": "sum by (source) (rate(dims_error_images_total[1m])) > 0", + "legendFormat": "error image {{source}}", + "refId": "B", + "datasource": { + "type": "prometheus", + "uid": "PROM" + } + } + ], + "fieldConfig": { + "defaults": { + "unit": "ops", + "custom": { + "lineWidth": 2, + "fillOpacity": 12, + "showPoints": "never", + "spanNulls": true, + "stacking": { + "mode": "none", + "group": "A" + } + }, + "color": { + "mode": "palette-classic" + } + }, + "overrides": [] + }, + "options": { + "legend": { + "displayMode": "table", + "placement": "right", + "showLegend": true, + "calcs": [ + "last", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + } + } + ] +} \ No newline at end of file diff --git a/test/endurance/observe/grafana/dashboards/provider.yml b/test/endurance/observe/grafana/dashboards/provider.yml new file mode 100644 index 0000000..da19cf2 --- /dev/null +++ b/test/endurance/observe/grafana/dashboards/provider.yml @@ -0,0 +1,7 @@ +apiVersion: 1 + +providers: + - name: mod_dims + type: file + options: + path: /etc/grafana/provisioning/dashboards diff --git a/test/endurance/observe/grafana/datasources/prometheus.yml b/test/endurance/observe/grafana/datasources/prometheus.yml new file mode 100644 index 0000000..6518213 --- /dev/null +++ b/test/endurance/observe/grafana/datasources/prometheus.yml @@ -0,0 +1,9 @@ +apiVersion: 1 + +datasources: + - name: Prometheus + type: prometheus + access: proxy + url: http://prometheus:9090 + isDefault: true + uid: PROM diff --git a/test/endurance/observe/prometheus.yml b/test/endurance/observe/prometheus.yml new file mode 100644 index 0000000..2eee2cd --- /dev/null +++ b/test/endurance/observe/prometheus.yml @@ -0,0 +1,10 @@ +# Scrapes the soak server's metrics port. The soak joins dims-soak-net, and +# the server answers to the alias "dims" on it. +global: + scrape_interval: 5s + evaluation_interval: 5s + +scrape_configs: + - job_name: mod_dims + static_configs: + - targets: ['dims:8001'] diff --git a/test/endurance/observe/up.sh b/test/endurance/observe/up.sh new file mode 100755 index 0000000..cdd5aaa --- /dev/null +++ b/test/endurance/observe/up.sh @@ -0,0 +1,26 @@ +#!/usr/bin/env bash +# +# Starts Prometheus and Grafana against a running soak. +# +# bash test/endurance/observe/up.sh +# +# Copyright 2026 Jeremy Collins +# SPDX-License-Identifier: Apache-2.0 +set -euo pipefail + +HERE="$(cd "$(dirname "$0")" && pwd)" + +if ! docker network inspect dims-soak-net >/dev/null 2>&1; then + echo "dims-soak-net is missing. Start the soak first:" >&2 + echo " bash test/endurance/run.sh" >&2 + exit 1 +fi + +docker compose -f "$HERE/compose.yaml" up -d + +address=$(ip -4 addr show scope global 2>/dev/null \ + | grep -oP 'inet \K[\d.]+' | head -1) + +echo +echo "Grafana: http://${address:-localhost}:3000/d/mod-dims-soak/mod-dims" +echo "Prometheus: docker compose -f $HERE/compose.yaml exec prometheus wget -qO- localhost:9090/-/healthy" diff --git a/test/endurance/run.sh b/test/endurance/run.sh index 7a8f6b2..8e27432 100755 --- a/test/endurance/run.sh +++ b/test/endurance/run.sh @@ -117,6 +117,8 @@ server_env+=( -e "DIMS_ALLOW_PRIVATE_ADDRESSES=on" -e "DIMS_STATUS_VERBOSE=on" -e "DIMS_ENCRYPTION_ALGORITHM=$algorithm" + # Port 8001 serves the metrics, so a run can be watched while it runs. + -e "DIMS_METRICS_ENABLED=on" # A child that is never recycled keeps whatever it leaked, so the trend # below measures the module rather than the recycling interval. The # production default is 10000. From 40f0b7682edee5b431169d83b9b3b72f96f2cbfa Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 15:20:17 -0400 Subject: [PATCH 15/16] Report 304 apart from every other status The module answers a conditional request with 304 through ap_meets_conditions. The response code list held no slot for it, so a caching client counted under "other". The dashboard splits its error ratio in two. A 4xx is the request the caller sent, and a 5xx is the module or its source failing. One number covering both reads as a fault when a caller sends a bad signature. --- src/metrics.c | 6 ++++-- src/metrics.h | 2 +- test/endurance/observe/README.md | 10 ++++++++-- .../observe/grafana/dashboards/mod_dims.json | 20 +++++++++---------- 4 files changed, 23 insertions(+), 15 deletions(-) diff --git a/src/metrics.c b/src/metrics.c index a7701f2..c48ef02 100644 --- a/src/metrics.c +++ b/src/metrics.c @@ -66,12 +66,14 @@ static const char *const outcome_name[DIMS_OUTCOME_COUNT] = { "network_refused" }; +/* 304 answers a conditional request, so a caching client sees it often. */ static const int code_value[DIMS_CODE_COUNT - 1] = { - 200, 400, 403, 404, 429, 500, 502, 503, 504 + 200, 304, 400, 403, 404, 429, 500, 502, 503, 504 }; static const char *const code_name[DIMS_CODE_COUNT] = { - "200", "400", "403", "404", "429", "500", "502", "503", "504", "other" + "200", "304", "400", "403", "404", "429", "500", "502", "503", "504", + "other" }; static const int origin_code_value[DIMS_ORIGIN_CODE_COUNT - 1] = { diff --git a/src/metrics.h b/src/metrics.h index 0d029f1..f63a5a1 100644 --- a/src/metrics.h +++ b/src/metrics.h @@ -27,7 +27,7 @@ typedef enum { * DimsOriginStatusMode forward copies whatever the origin returned. The last * slot of each holds every code outside its list. */ -#define DIMS_CODE_COUNT 10 +#define DIMS_CODE_COUNT 11 #define DIMS_ORIGIN_CODE_COUNT 13 /* Image formats reported by name. The last slot holds every other format. */ diff --git a/test/endurance/observe/README.md b/test/endurance/observe/README.md index fdea57d..fa972cd 100644 --- a/test/endurance/observe/README.md +++ b/test/endurance/observe/README.md @@ -20,8 +20,14 @@ no further setting. Six sections, from the top. -**Overview** reports the request rate, the error ratio, the p99 latency, -requests in flight, resident memory, and ready workers. +**Overview** reports the request rate, the two error ratios, the p99 latency, +requests in flight, and resident memory. + +The two ratios separate what the caller sent from what the module could not +serve. A 4xx is a bad signature, an unknown client, or an argument the module +cannot parse. A 5xx is the module or its source failing. A soak drives +malformed requests on purpose, so its 4xx line stays high and says nothing +about the module. **Request path** breaks the rate down by outcome, by status code, and by endpoint, with the latency quantiles beside them. diff --git a/test/endurance/observe/grafana/dashboards/mod_dims.json b/test/endurance/observe/grafana/dashboards/mod_dims.json index c8c8da5..add1d44 100644 --- a/test/endurance/observe/grafana/dashboards/mod_dims.json +++ b/test/endurance/observe/grafana/dashboards/mod_dims.json @@ -79,9 +79,9 @@ }, { "id": 103, - "title": "Error ratio", + "title": "Server error ratio", "type": "stat", - "description": "", + "description": "Responses the module could not serve, as a share of all responses. A 4xx is the caller's request, so it counts in the panel beside this one.", "datasource": { "type": "prometheus", "uid": "PROM" @@ -94,8 +94,8 @@ }, "targets": [ { - "expr": "sum(rate(dims_requests_total{outcome!=\"success\"}[1m])) / clamp_min(sum(rate(dims_requests_total[1m])), 0.001)", - "legendFormat": "errors", + "expr": "sum(rate(dims_responses_total{code=~\"5..\"}[1m])) / clamp_min(sum(rate(dims_responses_total[1m])), 0.001)", + "legendFormat": "5xx", "refId": "A", "datasource": { "type": "prometheus", @@ -274,10 +274,10 @@ } }, { - "id": 107, - "title": "Workers ready", + "id": 999, + "title": "Caller error ratio", "type": "stat", - "description": "", + "description": "Requests the module refused as malformed: a bad signature, an unknown client, or an argument it cannot parse. The caller sent these, so they report apart from a server error.", "datasource": { "type": "prometheus", "uid": "PROM" @@ -290,8 +290,8 @@ }, "targets": [ { - "expr": "dims_httpd_workers{state=\"ready\"}", - "legendFormat": "ready", + "expr": "sum(rate(dims_responses_total{code=~\"4..\"}[1m])) / clamp_min(sum(rate(dims_responses_total[1m])), 0.001)", + "legendFormat": "4xx", "refId": "A", "datasource": { "type": "prometheus", @@ -301,7 +301,7 @@ ], "fieldConfig": { "defaults": { - "unit": "short", + "unit": "percentunit", "custom": {}, "color": { "mode": "palette-classic" From e6289d8121e2ea5c9f70f434486a914239b778c4 Mon Sep 17 00:00:00 2001 From: Jeremy Collins Date: Tue, 1 Sep 2026 18:47:58 -0400 Subject: [PATCH 16/16] Keep the debug symbols in a valgrind run ImageMagick loads its coders with dlopen and unloads them before the process ends. Valgrind discards the symbols for unloaded code, so every frame inside ImageMagick printed as ???. --keep-debuginfo=yes holds them. A leak now names the function and the line: AcquireSemaphoreInfo through NewMagickWand, and GetMagicInfo through MagickReadImageBlob. --- test/endurance/run.sh | 1 + 1 file changed, 1 insertion(+) diff --git a/test/endurance/run.sh b/test/endurance/run.sh index 8e27432..b886875 100755 --- a/test/endurance/run.sh +++ b/test/endurance/run.sh @@ -164,6 +164,7 @@ if [ "$MODE" = valgrind ]; then --show-leak-kinds=definite,indirect \ --errors-for-leak-kinds=definite,indirect \ --num-callers=40 --error-exitcode=0 \ + --keep-debuginfo=yes \ --suppressions=/build/mod_dims/test/valgrind/dims.supp \ --log-file=/tmp/valgrind.log \ /usr/local/apache2/bin/httpd -X -DFOREGROUND >/dev/null