From 0cc3c9826bba9af86ae25e082f55e70aec713628 Mon Sep 17 00:00:00 2001 From: Ian Jackson Date: Thu, 23 Mar 2017 17:05:11 +0000 Subject: [PATCH 02/23] xenstored: Log when the write transaction rate limit bites Reported-by: Juergen Gross Signed-off-by: Ian Jackson --- tools/xenstore/xenstored_core.c | 1 + tools/xenstore/xenstored_domain.c | 25 +++++++++++++++++++++++++ tools/xenstore/xenstored_domain.h | 2 ++ 3 files changed, 28 insertions(+) diff --git a/tools/xenstore/xenstored_core.c b/tools/xenstore/xenstored_core.c index 069160a..07ca98e 100644 --- a/tools/xenstore/xenstored_core.c +++ b/tools/xenstore/xenstored_core.c @@ -374,6 +374,7 @@ static void initialize_fds(int sock, int *p_sock_pollfd_idx, POLLIN|POLLPRI); wrl_gettime_now(&now); + wrl_log_periodic(now); list_for_each_entry(conn, &connections, list) { if (conn->domain) { diff --git a/tools/xenstore/xenstored_domain.c b/tools/xenstore/xenstored_domain.c index 85fa658..9e81d33 100644 --- a/tools/xenstore/xenstored_domain.c +++ b/tools/xenstore/xenstored_domain.c @@ -23,6 +23,7 @@ #include #include #include +#include #include "utils.h" #include "talloc.h" @@ -79,6 +80,7 @@ struct domain /* write rate limit */ wrl_creditt wrl_credit; /* [ -wrl_config_writecost, +_dburst ] */ struct wrl_timestampt wrl_timestamp; + bool wrl_delay_logged; }; static LIST_HEAD(domains); @@ -770,6 +772,7 @@ long wrl_ntransactions; static long wrl_ndomains; static wrl_creditt wrl_reserve; /* [-wrl_config_newdoms_dburst, +_gburst ] */ +static time_t wrl_log_last_warning; /* 0: no previous warning */ void wrl_gettime_now(struct wrl_timestampt *now_wt) { @@ -919,6 +922,9 @@ void wrl_check_timeout(struct domain *domain, wakeup); } +#define WRL_LOG(now, ...) \ + (syslog(LOG_WARNING, "write rate limit: " __VA_ARGS__)) + void wrl_apply_debit_actual(struct domain *domain) { struct wrl_timestampt now; @@ -934,6 +940,25 @@ void wrl_apply_debit_actual(struct domain *domain) trace("wrl: domain %u credit=%ld (reserve=%ld)\n", domain->domid, (long)domain->wrl_credit, (long)wrl_reserve); + + if (domain->wrl_credit < 0) { + if (!domain->wrl_delay_logged++) { + WRL_LOG(now, "domain %ld is affected", + (long)domain->domid); + } else if (!wrl_log_last_warning) { + WRL_LOG(now, "rate limiting restarts"); + } + wrl_log_last_warning = now.sec; + } +} + +void wrl_log_periodic(struct wrl_timestampt now) +{ + if (wrl_log_last_warning && + (now.sec - wrl_log_last_warning) > WRL_LOGEVERY) { + WRL_LOG(now, "not in force recently"); + wrl_log_last_warning = 0; + } } void wrl_apply_debit_direct(struct connection *conn) diff --git a/tools/xenstore/xenstored_domain.h b/tools/xenstore/xenstored_domain.h index a008554..a9650cc 100644 --- a/tools/xenstore/xenstored_domain.h +++ b/tools/xenstore/xenstored_domain.h @@ -73,6 +73,7 @@ int domain_watch(struct connection *conn); #define WRL_DBURST 10 #define WRL_GBURST 1000 #define WRL_NEWDOMS 5 +#define WRL_LOGEVERY 120 /* seconds */ struct wrl_timestampt { time_t sec; @@ -88,6 +89,7 @@ void wrl_credit_update(struct domain *domain, struct wrl_timestampt now); void wrl_check_timeout(struct domain *domain, struct wrl_timestampt now, int *ptimeout); +void wrl_log_periodic(struct wrl_timestampt now); void wrl_apply_debit_direct(struct connection *conn); void wrl_apply_debit_trans_commit(struct connection *conn); -- 2.1.4