From 684996ee80c4b834f10c764a71a7f22dd2f23f83 Mon Sep 17 00:00:00 2001 From: Vsevolod Stakhov Date: Wed, 13 Nov 2019 13:58:09 +0000 Subject: [PATCH] [Minor] Add failure reason in the upstreams code --- contrib/librdns/rdns.h | 2 +- contrib/librdns/resolver.c | 9 +++---- src/libserver/dns.c | 6 ++--- src/libserver/fuzzy_backend_redis.c | 18 +++++++------- src/libstat/backends/redis_backend.c | 10 ++++---- src/libstat/learn_cache/redis_cache.c | 6 ++--- src/libutil/http_connection.c | 2 +- src/libutil/upstream.c | 34 ++++++++++++++++++++------- src/libutil/upstream.h | 2 +- src/lua/lua_upstream.c | 10 +++++++- src/plugins/fuzzy_check.c | 14 +++++------ src/rspamd_proxy.c | 23 +++++++++--------- test/rspamd_upstream_test.c | 4 ++-- 13 files changed, 84 insertions(+), 56 deletions(-) diff --git a/contrib/librdns/rdns.h b/contrib/librdns/rdns.h index 1b2f63b7a..5ea8f5952 100644 --- a/contrib/librdns/rdns.h +++ b/contrib/librdns/rdns.h @@ -169,7 +169,7 @@ struct rdns_upstream_context { void *ups_data); unsigned int (*count)(void *ups_data); void (*ok)(struct rdns_upstream_elt *elt, void *ups_data); - void (*fail)(struct rdns_upstream_elt *elt, void *ups_data); + void (*fail)(struct rdns_upstream_elt *elt, void *ups_data, const char *reason); }; /** diff --git a/contrib/librdns/resolver.c b/contrib/librdns/resolver.c index 6c4f29d8c..9c214c21e 100644 --- a/contrib/librdns/resolver.c +++ b/contrib/librdns/resolver.c @@ -334,7 +334,7 @@ rdns_process_timer (void *arg) if (req->resolver->ups && req->io->srv->ups_elt) { req->resolver->ups->fail (req->io->srv->ups_elt, - req->resolver->ups->data); + req->resolver->ups->data, "timeout waiting reply"); } else { UPSTREAM_FAIL (req->io->srv, time (NULL)); @@ -427,7 +427,7 @@ rdns_process_timer (void *arg) else if (r == -1) { if (req->resolver->ups && req->io->srv->ups_elt) { req->resolver->ups->fail (req->io->srv->ups_elt, - req->resolver->ups->data); + req->resolver->ups->data, "cannot send retransmit after timeout"); } else { UPSTREAM_FAIL (req->io->srv, time (NULL)); @@ -537,7 +537,7 @@ rdns_process_retransmit (int fd, void *arg) else if (r == -1) { if (req->resolver->ups && req->io->srv->ups_elt) { req->resolver->ups->fail (req->io->srv->ups_elt, - req->resolver->ups->data); + req->resolver->ups->data, "retransmit send failed"); } else { UPSTREAM_FAIL (req->io->srv, time (NULL)); @@ -790,7 +790,8 @@ rdns_make_request_full ( REF_RELEASE (req); if (resolver->ups && serv->ups_elt) { - resolver->ups->fail (serv->ups_elt, resolver->ups->data); + resolver->ups->fail (serv->ups_elt, resolver->ups->data, + "send IO error"); } else { UPSTREAM_FAIL (serv, time (NULL)); diff --git a/src/libserver/dns.c b/src/libserver/dns.c index 71b8adf9f..505e44a7a 100644 --- a/src/libserver/dns.c +++ b/src/libserver/dns.c @@ -36,7 +36,7 @@ static struct rdns_upstream_elt* rspamd_dns_select_upstream_retransmit ( static void rspamd_dns_upstream_ok (struct rdns_upstream_elt *elt, void *ups_data); static void rspamd_dns_upstream_fail (struct rdns_upstream_elt *elt, - void *ups_data); + void *ups_data, const gchar *reason); static unsigned int rspamd_dns_upstream_count (void *ups_data); static struct rdns_upstream_context rspamd_ups_ctx = { @@ -852,11 +852,11 @@ rspamd_dns_upstream_ok (struct rdns_upstream_elt *elt, static void rspamd_dns_upstream_fail (struct rdns_upstream_elt *elt, - void *ups_data) + void *ups_data, const gchar *reason) { struct upstream *up = elt->lib_data; - rspamd_upstream_fail (up, FALSE); + rspamd_upstream_fail (up, FALSE, reason); } static unsigned int diff --git a/src/libserver/fuzzy_backend_redis.c b/src/libserver/fuzzy_backend_redis.c index ed0813edf..7070773b3 100644 --- a/src/libserver/fuzzy_backend_redis.c +++ b/src/libserver/fuzzy_backend_redis.c @@ -444,7 +444,7 @@ rspamd_fuzzy_redis_shingles_callback (redisAsyncContext *c, gpointer r, msg_err_redis_session ("error getting shingles: %s", c->errstr); } - rspamd_upstream_fail (session->up, FALSE); + rspamd_upstream_fail (session->up, FALSE, strerror (errno)); } rspamd_fuzzy_redis_session_dtor (session, FALSE); @@ -582,7 +582,7 @@ rspamd_fuzzy_redis_check_callback (redisAsyncContext *c, gpointer r, msg_err_redis_session ("error getting hashes: %s", c->errstr); } - rspamd_upstream_fail (session->up, FALSE); + rspamd_upstream_fail (session->up, FALSE, strerror (errno)); } rspamd_fuzzy_redis_session_dtor (session, FALSE); @@ -651,7 +651,7 @@ rspamd_fuzzy_backend_check_redis (struct rspamd_fuzzy_backend *bk, rspamd_inet_address_get_port (addr)); if (session->ctx == NULL) { - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, strerror (errno)); rspamd_fuzzy_redis_session_dtor (session, TRUE); if (cb) { @@ -721,7 +721,7 @@ rspamd_fuzzy_redis_count_callback (redisAsyncContext *c, gpointer r, msg_err_redis_session ("error getting count: %s", c->errstr); } - rspamd_upstream_fail (session->up, FALSE); + rspamd_upstream_fail (session->up, FALSE, strerror (errno)); } rspamd_fuzzy_redis_session_dtor (session, FALSE); @@ -776,7 +776,7 @@ rspamd_fuzzy_backend_count_redis (struct rspamd_fuzzy_backend *bk, rspamd_inet_address_get_port (addr)); if (session->ctx == NULL) { - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, strerror (errno)); rspamd_fuzzy_redis_session_dtor (session, TRUE); if (cb) { @@ -844,7 +844,7 @@ rspamd_fuzzy_redis_version_callback (redisAsyncContext *c, gpointer r, msg_err_redis_session ("error getting version: %s", c->errstr); } - rspamd_upstream_fail (session->up, FALSE); + rspamd_upstream_fail (session->up, FALSE, strerror (errno)); } rspamd_fuzzy_redis_session_dtor (session, FALSE); @@ -900,7 +900,7 @@ rspamd_fuzzy_backend_version_redis (struct rspamd_fuzzy_backend *bk, rspamd_inet_address_get_port (addr)); if (session->ctx == NULL) { - rspamd_upstream_fail (up, FALSE); + rspamd_upstream_fail (up, FALSE, strerror (errno)); rspamd_fuzzy_redis_session_dtor (session, TRUE); if (cb) { @@ -1334,7 +1334,7 @@ rspamd_fuzzy_redis_update_callback (redisAsyncContext *c, gpointer r, msg_err_redis_session ("error sending update to redis: %s", c->errstr); } - rspamd_upstream_fail (session->up, FALSE); + rspamd_upstream_fail (session->up, FALSE, strerror (errno)); } rspamd_fuzzy_redis_session_dtor (session, FALSE); @@ -1460,7 +1460,7 @@ rspamd_fuzzy_backend_update_redis (struct rspamd_fuzzy_backend *bk, rspamd_inet_address_get_port (addr)); if (session->ctx == NULL) { - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, strerror (errno)); rspamd_fuzzy_redis_session_dtor (session, TRUE); if (cb) { diff --git a/src/libstat/backends/redis_backend.c b/src/libstat/backends/redis_backend.c index 90afe66d3..f21431590 100644 --- a/src/libstat/backends/redis_backend.c +++ b/src/libstat/backends/redis_backend.c @@ -946,7 +946,7 @@ rspamd_redis_stat_keys (redisAsyncContext *c, gpointer r, gpointer priv) msg_err ("cannot get keys to gather stat: unknown error"); } - rspamd_upstream_fail (cbdata->selected, FALSE); + rspamd_upstream_fail (cbdata->selected, FALSE, c->errstr); rspamd_redis_async_cbdata_cleanup (cbdata); redis_elt->cbdata = NULL; } @@ -1106,7 +1106,7 @@ rspamd_redis_timeout (EV_P_ ev_timer *w, int revents) msg_err_task_check ("connection to redis server %s timed out", rspamd_upstream_name (rt->selected)); - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, "timeout"); if (rt->redis) { redis = rt->redis; @@ -1207,7 +1207,7 @@ rspamd_redis_processed (redisAsyncContext *c, gpointer r, gpointer priv) rspamd_upstream_name (rt->selected), c->errstr); if (rt->redis) { - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, c->errstr); } if (!rt->err) { @@ -1338,7 +1338,7 @@ rspamd_redis_connected (redisAsyncContext *c, gpointer r, gpointer priv) else if (rt->has_event) { msg_err_task ("error getting reply from redis server %s: %s", rspamd_upstream_name (rt->selected), c->errstr); - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, c->errstr); if (!rt->err) { g_set_error (&rt->err, rspamd_redis_stat_quark (), c->err, @@ -1369,7 +1369,7 @@ rspamd_redis_learned (redisAsyncContext *c, gpointer r, gpointer priv) rspamd_upstream_name (rt->selected), c->errstr); if (rt->redis) { - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, c->errstr); } if (!rt->err) { diff --git a/src/libstat/learn_cache/redis_cache.c b/src/libstat/learn_cache/redis_cache.c index 0df3783ab..301232d28 100644 --- a/src/libstat/learn_cache/redis_cache.c +++ b/src/libstat/learn_cache/redis_cache.c @@ -114,7 +114,7 @@ rspamd_redis_cache_timeout (EV_P_ ev_timer *w, int revents) msg_err_task ("connection to redis server %s timed out", rspamd_upstream_name (rt->selected)); - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, "timeout"); if (rt->has_event) { rspamd_session_remove_event (task->s, rspamd_redis_cache_fin, rt); @@ -166,7 +166,7 @@ rspamd_stat_cache_redis_get (redisAsyncContext *c, gpointer r, gpointer priv) rspamd_upstream_ok (rt->selected); } else { - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, c->errstr); } if (rt->has_event) { @@ -188,7 +188,7 @@ rspamd_stat_cache_redis_set (redisAsyncContext *c, gpointer r, gpointer priv) rspamd_upstream_ok (rt->selected); } else { - rspamd_upstream_fail (rt->selected, FALSE); + rspamd_upstream_fail (rt->selected, FALSE, c->errstr); } if (rt->has_event) { diff --git a/src/libutil/http_connection.c b/src/libutil/http_connection.c index ca87c205a..a71c6fe75 100644 --- a/src/libutil/http_connection.c +++ b/src/libutil/http_connection.c @@ -1197,7 +1197,7 @@ rspamd_http_connection_new_client (struct rspamd_http_context *ctx, msg_info ("cannot connect to http proxy %s: %s", rspamd_inet_address_to_string_pretty (proxy_addr), strerror (errno)); - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, strerror (errno)); return NULL; } diff --git a/src/libutil/upstream.c b/src/libutil/upstream.c index 94d694d77..7d8b81048 100644 --- a/src/libutil/upstream.c +++ b/src/libutil/upstream.c @@ -735,13 +735,19 @@ rspamd_upstream_set_inactive (struct upstream_list *ls, struct upstream *upstrea } void -rspamd_upstream_fail (struct upstream *upstream, gboolean addr_failure) +rspamd_upstream_fail (struct upstream *upstream, + gboolean addr_failure, + const gchar *reason) { gdouble error_rate = 0, max_error_rate = 0; gdouble sec_last, sec_cur; struct upstream_addr_elt *addr_elt; struct upstream_list_watcher *w; + msg_debug_upstream ("upstream %s failed; reason: %s", + upstream->name, + reason); + if (upstream->ctx && upstream->active_idx != -1) { sec_cur = rspamd_get_ticks (FALSE); @@ -780,27 +786,38 @@ rspamd_upstream_fail (struct upstream *upstream, gboolean addr_failure) if (error_rate > max_error_rate) { /* Remove upstream from the active list */ if (upstream->ls->ups->len > 1) { - msg_debug_upstream ("mark upstream %s inactive: %.2f " + msg_debug_upstream ("mark upstream %s inactive; " + "reason: %s; %.2f " "error rate (%d errors), " "%.2f max error rate, " "%.1f first error time, " "%.1f current ts, " "%d upstreams left", - upstream->name, error_rate, upstream->errors, - max_error_rate, sec_last, sec_cur, + upstream->name, + reason, + error_rate, + upstream->errors, + max_error_rate, + sec_last, + sec_cur, upstream->ls->alive->len - 1); rspamd_upstream_set_inactive (upstream->ls, upstream); upstream->errors = 0; } else { msg_debug_upstream ("cannot mark last alive upstream %s " - "inactive: %.2f " + "inactive; reason: %s; %.2f " "error rate (%d errors), " "%.2f max error rate, " "%.1f first error time, " "%.1f current ts", - upstream->name, error_rate, upstream->errors, - max_error_rate, sec_last, sec_cur); + upstream->name, + reason, + error_rate, + upstream->errors, + max_error_rate, + sec_last, + sec_cur); /* Just re-resolve addresses */ if (sec_cur - sec_last > upstream->ls->limits->revive_time) { upstream->errors = 0; @@ -819,7 +836,8 @@ rspamd_upstream_fail (struct upstream *upstream, gboolean addr_failure) if (addr_failure) { /* Also increase count of errors for this specific address */ if (upstream->addrs.addr) { - addr_elt = g_ptr_array_index (upstream->addrs.addr, upstream->addrs.cur); + addr_elt = g_ptr_array_index (upstream->addrs.addr, + upstream->addrs.cur); addr_elt->errors++; } } diff --git a/src/libutil/upstream.h b/src/libutil/upstream.h index 0581a314c..89bcd9b52 100644 --- a/src/libutil/upstream.h +++ b/src/libutil/upstream.h @@ -60,7 +60,7 @@ void rspamd_upstreams_library_config (struct rspamd_config *cfg, /** * Add an error to an upstream */ -void rspamd_upstream_fail (struct upstream *upstream, gboolean addr_failure); +void rspamd_upstream_fail (struct upstream *upstream, gboolean addr_failure, const gchar *reason); /** * Increase upstream successes count diff --git a/src/lua/lua_upstream.c b/src/lua/lua_upstream.c index 7ba77839f..2f04d7059 100644 --- a/src/lua/lua_upstream.c +++ b/src/lua/lua_upstream.c @@ -129,14 +129,22 @@ lua_upstream_fail (lua_State *L) LUA_TRACE_POINT; struct upstream *up = lua_check_upstream (L); gboolean fail_addr = FALSE; + const gchar *reason = "unknown"; if (up) { if (lua_isboolean (L, 2)) { fail_addr = lua_toboolean (L, 2); + + if (lua_isstring (L, 3)) { + reason = lua_tostring (L, 3); + } + } + else if (lua_isstring (L, 2)) { + reason = lua_tostring (L, 2); } - rspamd_upstream_fail (up, fail_addr); + rspamd_upstream_fail (up, fail_addr, reason); } return 0; diff --git a/src/plugins/fuzzy_check.c b/src/plugins/fuzzy_check.c index 5c3994559..57e9bf8cb 100644 --- a/src/plugins/fuzzy_check.c +++ b/src/plugins/fuzzy_check.c @@ -2255,7 +2255,7 @@ fuzzy_check_timer_callback (gint fd, short what, void *arg) rspamd_inet_address_to_string_pretty ( rspamd_upstream_addr_cur (session->server)), session->retransmits); - rspamd_upstream_fail (session->server, TRUE); + rspamd_upstream_fail (session->server, TRUE, "timeout"); if (session->item) { rspamd_symcache_item_async_dec_check (session->task, session->item, M); @@ -2337,7 +2337,7 @@ fuzzy_check_io_callback (gint fd, short what, void *arg) session->state == 1 ? "read" : "write", errno, strerror (errno)); - rspamd_upstream_fail (session->server, TRUE); + rspamd_upstream_fail (session->server, TRUE, strerror (errno)); if (session->item) { rspamd_symcache_item_async_dec_check (session->task, session->item, M); @@ -2378,7 +2378,7 @@ fuzzy_controller_timer_callback (gint fd, short what, void *arg) task = session->task; if (session->retransmits >= session->rule->ctx->retransmits) { - rspamd_upstream_fail (session->server, TRUE); + rspamd_upstream_fail (session->server, TRUE, "timeout"); msg_err_task_check ("got IO timeout with server %s(%s), " "after %d retransmits", rspamd_upstream_name (session->server), @@ -2594,7 +2594,7 @@ fuzzy_controller_io_callback (gint fd, short what, void *arg) rspamd_inet_address_to_string_pretty ( rspamd_upstream_addr_cur (session->server)), errno, strerror (errno)); - rspamd_upstream_fail (session->server, FALSE); + rspamd_upstream_fail (session->server, FALSE, strerror (errno)); } /* @@ -2798,7 +2798,7 @@ register_fuzzy_client_call (struct rspamd_task *task, rspamd_inet_address_to_string_pretty (addr), errno, strerror (errno)); - rspamd_upstream_fail (selected, TRUE); + rspamd_upstream_fail (selected, TRUE, strerror (errno)); g_ptr_array_free (commands, TRUE); } else { /* Create session for a socket */ @@ -2924,7 +2924,7 @@ register_fuzzy_controller_call (struct rspamd_http_connection_entry *entry, rspamd_inet_address_to_string_pretty (addr), rule->name, strerror (errno)); - rspamd_upstream_fail (selected, TRUE); + rspamd_upstream_fail (selected, TRUE, strerror (errno)); } else { s = @@ -3287,7 +3287,7 @@ fuzzy_check_send_lua_learn (struct fuzzy_rule *rule, if ((sock = rspamd_inet_address_connect (addr, SOCK_DGRAM, TRUE)) == -1) { - rspamd_upstream_fail (selected, TRUE); + rspamd_upstream_fail (selected, TRUE, strerror (errno)); } else { s = rspamd_mempool_alloc0 (task->task_pool, diff --git a/src/rspamd_proxy.c b/src/rspamd_proxy.c index fd5b181f8..6cc2e592d 100644 --- a/src/rspamd_proxy.c +++ b/src/rspamd_proxy.c @@ -1293,7 +1293,7 @@ proxy_backend_mirror_error_handler (struct rspamd_http_connection *conn, GError msg_info_session ("abnormally closing connection from backend: %s:%s, " "error: %e", bk_conn->name, - rspamd_inet_address_to_string ( + rspamd_inet_address_to_string_pretty ( rspamd_upstream_addr_cur (bk_conn->up)), err); @@ -1301,7 +1301,7 @@ proxy_backend_mirror_error_handler (struct rspamd_http_connection *conn, GError bk_conn->err = rspamd_mempool_strdup (session->pool, err->message); } - rspamd_upstream_fail (bk_conn->up, FALSE); + rspamd_upstream_fail (bk_conn->up, FALSE, err ? err->message : "unknown"); proxy_backend_close_connection (bk_conn); REF_RELEASE (bk_conn->s); @@ -1378,7 +1378,7 @@ proxy_open_mirror_connections (struct rspamd_proxy_session *session) if (bk_conn->backend_sock == -1) { msg_err_session ("cannot connect upstream for %s", m->name); - rspamd_upstream_fail (bk_conn->up, TRUE); + rspamd_upstream_fail (bk_conn->up, TRUE, strerror (errno)); continue; } @@ -1519,12 +1519,12 @@ proxy_backend_master_error_handler (struct rspamd_http_connection *conn, GError session = bk_conn->s; session->retries ++; msg_info_session ("abnormally closing connection from backend: %s, error: %e," - " retries left: %d", - rspamd_inet_address_to_string ( - rspamd_upstream_addr_cur (session->master_conn->up)), - err, - session->ctx->max_retries - session->retries); - rspamd_upstream_fail (bk_conn->up, FALSE); + " retries left: %d", + rspamd_inet_address_to_string_pretty ( + rspamd_upstream_addr_cur (session->master_conn->up)), + err, + session->ctx->max_retries - session->retries); + rspamd_upstream_fail (bk_conn->up, FALSE, err ? err->message : "unknown"); proxy_backend_close_connection (session->master_conn); if (session->ctx->max_retries > 0 && @@ -1889,10 +1889,11 @@ retry: if (session->master_conn->backend_sock == -1) { msg_err_session ("cannot connect upstream: %s(%s)", host ? hostbuf : "default", - rspamd_inet_address_to_string ( + rspamd_inet_address_to_string_pretty ( rspamd_upstream_addr_cur ( session->master_conn->up))); - rspamd_upstream_fail (session->master_conn->up, TRUE); + rspamd_upstream_fail (session->master_conn->up, TRUE, + strerror (errno)); session->retries ++; goto retry; } diff --git a/test/rspamd_upstream_test.c b/test/rspamd_upstream_test.c index bbe47fc04..263a28e75 100644 --- a/test/rspamd_upstream_test.c +++ b/test/rspamd_upstream_test.c @@ -106,7 +106,7 @@ rspamd_upstream_test_func (void) next_addr = rspamd_upstream_addr_next (up); g_assert (rspamd_inet_address_get_af (next_addr) == AF_INET6); /* Test errors with IPv6 */ - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, NULL); /* Now we should have merely IPv4 addresses in rotation */ addr = rspamd_upstream_addr_next (up); for (i = 0; i < 256; i++) { @@ -169,7 +169,7 @@ rspamd_upstream_test_func (void) up = rspamd_upstream_get (ls, RSPAMD_UPSTREAM_MASTER_SLAVE, NULL, 0); for (i = 0; i < 100; i ++) { - rspamd_upstream_fail (up, TRUE); + rspamd_upstream_fail (up, TRUE, NULL); } g_assert (rspamd_upstreams_alive (ls) == 2); -- 2.39.5