From 6d987a66bcfc4f3da6bea79c8e011a245e16e64d Mon Sep 17 00:00:00 2001 From: TJ Saunders Date: Sun, 26 Mar 2017 10:55:56 -0700 Subject: [PATCH] When we emit a counter/timer for an unsampled metric, make sure that fact is properly communicated to statsd. Otherwise its aggregration for that metric will be wrong. --- metric.c | 26 +++++++++++++++++++++----- metric.h | 13 ++++++++++--- mod_statsd.c | 40 ++++++++++++++++++++-------------------- t/api/metric.c | 26 +++++++++++++++++--------- 4 files changed, 68 insertions(+), 37 deletions(-) diff --git a/metric.c b/metric.c index 65f51ba..742c562 100644 --- a/metric.c +++ b/metric.c @@ -89,7 +89,7 @@ static int write_metric(struct statsd *statsd, const char *metric_type, } int statsd_metric_counter(struct statsd *statsd, const char *name, - int64_t incr) { + int64_t incr, int flags) { float sampling; if (statsd == NULL || @@ -98,11 +98,18 @@ int statsd_metric_counter(struct statsd *statsd, const char *name, return -1; } - sampling = statsd_statsd_get_sampling(statsd); + if (flags & STATSD_METRIC_FL_IGNORE_SAMPLING) { + sampling = 1.0; + + } else { + sampling = statsd_statsd_get_sampling(statsd); + } + return write_metric(statsd, "c", name, "", incr, sampling); } -int statsd_metric_timer(struct statsd *statsd, const char *name, uint64_t ms) { +int statsd_metric_timer(struct statsd *statsd, const char *name, uint64_t ms, + int flags) { float sampling; if (statsd == NULL || @@ -117,7 +124,13 @@ int statsd_metric_timer(struct statsd *statsd, const char *name, uint64_t ms) { ms = STATSD_MAX_TIME_MS; } - sampling = statsd_statsd_get_sampling(statsd); + if (flags & STATSD_METRIC_FL_IGNORE_SAMPLING) { + sampling = 1.0; + + } else { + sampling = statsd_statsd_get_sampling(statsd); + } + return write_metric(statsd, "ms", name, "", ms, sampling); } @@ -133,7 +146,7 @@ int statsd_metric_gauge(struct statsd *statsd, const char *name, int64_t val, val_prefix = ""; - if (flags & STATSD_METRIC_GAUGE_FL_ADJUST) { + if (flags & STATSD_METRIC_FL_GAUGE_ADJUST) { if (val > 0) { val_prefix = "+"; } @@ -147,5 +160,8 @@ int statsd_metric_gauge(struct statsd *statsd, const char *name, int64_t val, } } + /* Unlikes counters and timers, gauges are NOT subject to sampling frequency; + * the statsd protocol does not allow for this, and rightly so. + */ return write_metric(statsd, "g", name, val_prefix, val, 1.0); } diff --git a/metric.h b/metric.h index e61407f..3ce2655 100644 --- a/metric.h +++ b/metric.h @@ -28,14 +28,21 @@ #include "mod_statsd.h" #include "statsd.h" -int statsd_metric_counter(struct statsd *statsd, const char *name, int64_t incr); -int statsd_metric_timer(struct statsd *statsd, const char *name, uint64_t ms); +int statsd_metric_counter(struct statsd *statsd, const char *name, int64_t incr, + int flags); +int statsd_metric_timer(struct statsd *statsd, const char *name, uint64_t ms, + int flags); int statsd_metric_gauge(struct statsd *statsd, const char *name, int64_t val, int flags); /* Use this flag, for a gauge, for adjusting the existing gauge value, rather * that setting it. */ -#define STATSD_METRIC_GAUGE_FL_ADJUST 0x0001 +#define STATSD_METRIC_FL_GAUGE_ADJUST 0x0001 + +/* Usage this flag to indicate that the metric is NOT subject to the sampling + * frequency. + */ +#define STATSD_METRIC_FL_IGNORE_SAMPLING 0x0002 #endif /* MOD_STATSD_METRIC_H */ diff --git a/mod_statsd.c b/mod_statsd.c index c4073cc..a925cc8 100644 --- a/mod_statsd.c +++ b/mod_statsd.c @@ -323,18 +323,18 @@ static void log_tls_auth_metrics(cmd_rec *cmd, uint64_t now_ms) { char *handshake_metric, *proto_metric, *protocol_env, *cipher_env; handshake_metric = get_tls_metric(cmd->tmp_pool, "handshake.ctrl"); - statsd_metric_counter(statsd, handshake_metric, 1); + statsd_metric_counter(statsd, handshake_metric, 1, 0); proto_metric = get_conn_metric(cmd->tmp_pool, "ftps"); - statsd_metric_counter(statsd, proto_metric, 1); - statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_counter(statsd, proto_metric, 1, 0); + statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_FL_GAUGE_ADJUST); start_ms = pr_table_get(cmd->notes, "start_ms", NULL); if (start_ms != NULL) { uint64_t handshake_ms; handshake_ms = now_ms - *start_ms; - statsd_metric_timer(statsd, handshake_metric, handshake_ms); + statsd_metric_timer(statsd, handshake_metric, handshake_ms, 0); } cipher_env = pr_env_get(cmd->tmp_pool, "TLS_CIPHER"); @@ -343,7 +343,7 @@ static void log_tls_auth_metrics(cmd_rec *cmd, uint64_t now_ms) { cipher_metric = get_tls_metric(cmd->tmp_pool, pstrcat(cmd->tmp_pool, "cipher.", cipher_env, NULL)); - statsd_metric_counter(statsd, cipher_metric, 1); + statsd_metric_counter(statsd, cipher_metric, 1, 0); } protocol_env = pr_env_get(cmd->tmp_pool, "TLS_PROTOCOL"); @@ -352,7 +352,7 @@ static void log_tls_auth_metrics(cmd_rec *cmd, uint64_t now_ms) { protocol_metric = get_tls_metric(cmd->tmp_pool, pstrcat(cmd->tmp_pool, "protocol.", protocol_env, NULL)); - statsd_metric_counter(statsd, protocol_metric, 1); + statsd_metric_counter(statsd, protocol_metric, 1, 0); } } @@ -407,14 +407,14 @@ static void log_cmd_metrics(cmd_rec *cmd, int had_error) { } metric = get_cmd_metric(cmd->tmp_pool, cmd->argv[0]); - statsd_metric_counter(statsd, metric, 1); + statsd_metric_counter(statsd, metric, 1, 0); start_ms = pr_table_get(cmd->notes, "start_ms", NULL); if (start_ms != NULL) { uint64_t response_ms; response_ms = now_ms - *start_ms; - statsd_metric_timer(statsd, metric, response_ms); + statsd_metric_timer(statsd, metric, response_ms, 0); } log_tls_metrics(cmd, had_error, now_ms); @@ -431,8 +431,8 @@ static void log_cmd_metrics(cmd_rec *cmd, int had_error) { * connection, not FTPS or SFTP or anything else. */ proto_metric = get_conn_metric(cmd->tmp_pool, "ftp"); - statsd_metric_counter(statsd, proto_metric, 1); - statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_counter(statsd, proto_metric, 1, 0); + statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_FL_GAUGE_ADJUST); } } @@ -459,15 +459,15 @@ static void statsd_exit_ev(const void *event_data, void *user_data) { uint64_t now_ms = 0, sess_ms; metric = get_conn_metric(session.pool, NULL); - statsd_metric_gauge(statsd, metric, -1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_gauge(statsd, metric, -1, STATSD_METRIC_FL_GAUGE_ADJUST); proto = pr_session_get_protocol(0); metric = get_conn_metric(session.pool, proto); - statsd_metric_gauge(statsd, metric, -1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_gauge(statsd, metric, -1, STATSD_METRIC_FL_GAUGE_ADJUST); pr_gettimeofday_millis(&now_ms); sess_ms = now_ms - statsd_sess_start_ms; - statsd_metric_timer(statsd, metric, sess_ms); + statsd_metric_timer(statsd, metric, sess_ms, 0); statsd_statsd_close(statsd); statsd = NULL; @@ -556,8 +556,8 @@ static void statsd_ssh2_sftp_sess_opened_ev(const void *event_data, tmp_pool = make_sub_pool(session.pool); proto_metric = get_conn_metric(tmp_pool, "sftp"); - statsd_metric_counter(statsd, proto_metric, 1); - statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_counter(statsd, proto_metric, 1, 0); + statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_FL_GAUGE_ADJUST); statsd_statsd_flush(statsd); destroy_pool(tmp_pool); } @@ -573,8 +573,8 @@ static void statsd_ssh2_scp_sess_opened_ev(const void *event_data, tmp_pool = make_sub_pool(session.pool); proto_metric = get_conn_metric(tmp_pool, "scp"); - statsd_metric_counter(statsd, proto_metric, 1); - statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_counter(statsd, proto_metric, 1, 0); + statsd_metric_gauge(statsd, proto_metric, 1, STATSD_METRIC_FL_GAUGE_ADJUST); statsd_statsd_flush(statsd); destroy_pool(tmp_pool); } @@ -589,7 +589,7 @@ static void incr_timeout_metric(const char *name) { tmp_pool = make_sub_pool(session.pool); metric = get_timeout_metric(tmp_pool, name); - statsd_metric_counter(statsd, metric, 1); + statsd_metric_counter(statsd, metric, 1, STATSD_METRIC_FL_IGNORE_SAMPLING); statsd_statsd_flush(statsd); destroy_pool(tmp_pool); } @@ -625,7 +625,7 @@ static void incr_tls_handshake_error_metric(const char *name) { */ metric = get_tls_metric(tmp_pool, name); - statsd_metric_counter(statsd, metric, 1); + statsd_metric_counter(statsd, metric, 1, STATSD_METRIC_FL_IGNORE_SAMPLING); statsd_statsd_flush(statsd); destroy_pool(tmp_pool); } @@ -714,7 +714,7 @@ static int statsd_sess_init(void) { } metric = get_conn_metric(session.pool, NULL); - statsd_metric_gauge(statsd, metric, 1, STATSD_METRIC_GAUGE_FL_ADJUST); + statsd_metric_gauge(statsd, metric, 1, STATSD_METRIC_FL_GAUGE_ADJUST); statsd_statsd_flush(statsd); pr_event_register(&statsd_module, "core.exit", statsd_exit_ev, NULL); diff --git a/t/api/metric.c b/t/api/metric.c index 4de8583..1671884 100644 --- a/t/api/metric.c +++ b/t/api/metric.c @@ -67,7 +67,7 @@ START_TEST (metric_counter_test) { struct statsd *statsd; mark_point(); - res = statsd_metric_counter(NULL, NULL, 0); + res = statsd_metric_counter(NULL, NULL, 0, 0); fail_unless(res < 0, "Failed to handle null statsd"); fail_unless(errno == EINVAL, "Expected EINVAL (%d), got %s (%d)", EINVAL, strerror(errno), errno); @@ -80,13 +80,17 @@ START_TEST (metric_counter_test) { strerror(errno)); mark_point(); - res = statsd_metric_counter(statsd, NULL, 0); + res = statsd_metric_counter(statsd, NULL, 0, 0); fail_unless(res < 0, "Failed to handle null name"); fail_unless(errno == EINVAL, "Expected EINVAL (%d), got %s (%d)", EINVAL, strerror(errno), errno); mark_point(); - res = statsd_metric_counter(statsd, "foo", 0); + res = statsd_metric_counter(statsd, "foo", 0, 0); + fail_unless(res == 0, "Failed to set counter: %s", strerror(errno)); + + mark_point(); + res = statsd_metric_counter(statsd, "foo", 0, STATSD_METRIC_FL_IGNORE_SAMPLING); fail_unless(res == 0, "Failed to set counter: %s", strerror(errno)); mark_point(); @@ -104,7 +108,7 @@ START_TEST (metric_timer_test) { uint64_t ms; mark_point(); - res = statsd_metric_timer(NULL, NULL, 0); + res = statsd_metric_timer(NULL, NULL, 0, 0); fail_unless(res < 0, "Failed to handle null statsd"); fail_unless(errno == EINVAL, "Expected EINVAL (%d), got %s (%d)", EINVAL, strerror(errno), errno); @@ -117,7 +121,7 @@ START_TEST (metric_timer_test) { strerror(errno)); mark_point(); - res = statsd_metric_timer(statsd, NULL, 0); + res = statsd_metric_timer(statsd, NULL, 0, 0); fail_unless(res < 0, "Failed to handle null name"); fail_unless(errno == EINVAL, "Expected EINVAL (%d), got %s (%d)", EINVAL, strerror(errno), errno); @@ -125,14 +129,18 @@ START_TEST (metric_timer_test) { ms = 1; mark_point(); - res = statsd_metric_timer(statsd, "foo", ms); + res = statsd_metric_timer(statsd, "foo", ms, 0); fail_unless(res == 0, "Failed to set timer: %s", strerror(errno)); /* Deliberately use a very large timer, to test the truncation. */ ms = 315360000000UL; mark_point(); - res = statsd_metric_timer(statsd, "bar", ms); + res = statsd_metric_timer(statsd, "bar", ms, 0); + fail_unless(res == 0, "Failed to set timer: %s", strerror(errno)); + + mark_point(); + res = statsd_metric_timer(statsd, "bar", ms, STATSD_METRIC_FL_IGNORE_SAMPLING); fail_unless(res == 0, "Failed to set timer: %s", strerror(errno)); mark_point(); @@ -172,11 +180,11 @@ START_TEST (metric_gauge_test) { fail_unless(res == 0, "Failed to set gauge: %s", strerror(errno)); mark_point(); - res = statsd_metric_gauge(statsd, "foo", 1, STATSD_METRIC_GAUGE_FL_ADJUST); + res = statsd_metric_gauge(statsd, "foo", 1, STATSD_METRIC_FL_GAUGE_ADJUST); fail_unless(res == 0, "Failed to set gauge: %s", strerror(errno)); mark_point(); - res = statsd_metric_gauge(statsd, "foo", -1, STATSD_METRIC_GAUGE_FL_ADJUST); + res = statsd_metric_gauge(statsd, "foo", -1, STATSD_METRIC_FL_GAUGE_ADJUST); fail_unless(res == 0, "Failed to set gauge: %s", strerror(errno)); mark_point();