core: implement per unit journal rate limiting

Add LogRateLimitIntervalSec= and LogRateLimitBurst= options for
services. If provided, these values get passed to the journald
client context, and those values are used in the rate limiting
function in the journal over the the journald.conf values.

Part of #10230
This commit is contained in:
Anita Zhang 2018-10-07 20:28:36 -07:00 committed by Lennart Poettering
parent 9fcdab9c87
commit 90fc172e19
17 changed files with 232 additions and 28 deletions

View File

@ -52,7 +52,8 @@ dropped, other services' messages are unaffected.
The limits controlling when messages are dropped may be configured
with RateLimitIntervalSec= and RateLimitBurst= in
/etc/systemd/journald.conf. See journald.conf(5) for details.
/etc/systemd/journald.conf or LogRateLimitIntervalSec= and LogRateLimitBurst=
in the unit file. See journald.conf(5) and systemd.exec(5) for details.
-- e9bf28e6e834481bb6f48f548ad13606
Subject: Journal messages have been missed

View File

@ -135,6 +135,8 @@ All execution-related settings are available for transient units.
✓ SyslogLevelPrefix=
✓ LogLevelMax=
✓ LogExtraFields=
✓ LogRateLimitIntervalSec=
✓ LogRateLimitBurst=
✓ SecureBits=
✓ CapabilityBoundingSet=
✓ AmbientCapabilities=

View File

@ -140,7 +140,13 @@
following units: <literal>s</literal>, <literal>min</literal>,
<literal>h</literal>, <literal>ms</literal>,
<literal>us</literal>. To turn off any kind of rate limiting,
set either value to 0.</para></listitem>
set either value to 0.</para>
<para>If a service provides rate limits for itself through
<varname>LogRateLimitIntervalSec=</varname> and/or <varname>LogRateLimitBurst=</varname>
in <citerefentry><refentrytitle>systemd.exec</refentrytitle><manvolnum>5</manvolnum></citerefentry>,
those values will override the settings specified here.</para>
</listitem>
</varlistentry>
<varlistentry>

View File

@ -1947,6 +1947,22 @@ StandardInputData=SWNrIHNpdHplIGRhIHVuJyBlc3NlIEtsb3BzLAp1ZmYgZWVtYWwga2xvcHAncy
matching. Assign an empty string to reset the list.</para></listitem>
</varlistentry>
<varlistentry>
<term><varname>LogRateLimitIntervalSec=</varname></term>
<term><varname>LogRateLimitBurst=</varname></term>
<listitem><para>Configures the rate limiting that is applied to messages generated by this unit. If, in the
time interval defined by <varname>LogRateLimitIntervalSec=</varname>, more messages than specified in
<varname>LogRateLimitBurst=</varname> are logged by a service, all further messages within the interval are
dropped until the interval is over. A message about the number of dropped messages is generated. The time
specification for <varname>LogRateLimitIntervalSec=</varname> may be specified in the following units: "s",
"min", "h", "ms", "us" (see
<citerefentry><refentrytitle>systemd.time</refentrytitle><manvolnum>7</manvolnum></citerefentry> for details).
The default settings are set by <varname>RateLimitIntervalSec=</varname> and <varname>RateLimitBurst=</varname>
configured in <citerefentry><refentrytitle>journald.conf</refentrytitle><manvolnum>5</manvolnum></citerefentry>.
</para></listitem>
</varlistentry>
<varlistentry>
<term><varname>SyslogIdentifier=</varname></term>

View File

@ -718,6 +718,8 @@ const sd_bus_vtable bus_exec_vtable[] = {
SD_BUS_PROPERTY("SyslogLevel", "i", property_get_syslog_level, offsetof(ExecContext, syslog_priority), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("SyslogFacility", "i", property_get_syslog_facility, offsetof(ExecContext, syslog_priority), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("LogLevelMax", "i", bus_property_get_int, offsetof(ExecContext, log_level_max), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("LogRateLimitIntervalUSec", "t", bus_property_get_usec, offsetof(ExecContext, log_rate_limit_interval_usec), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("LogRateLimitBurst", "u", bus_property_get_unsigned, offsetof(ExecContext, log_rate_limit_burst), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("LogExtraFields", "aay", property_get_log_extra_fields, 0, SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("SecureBits", "i", bus_property_get_int, offsetof(ExecContext, secure_bits), SD_BUS_VTABLE_PROPERTY_CONST),
SD_BUS_PROPERTY("CapabilityBoundingSet", "t", NULL, offsetof(ExecContext, capability_bounding_set), SD_BUS_VTABLE_PROPERTY_CONST),
@ -1067,6 +1069,12 @@ int bus_exec_context_set_transient_property(
if (streq(name, "LogLevelMax"))
return bus_set_transient_log_level(u, name, &c->log_level_max, message, flags, error);
if (streq(name, "LogRateLimitIntervalUSec"))
return bus_set_transient_usec(u, name, &c->log_rate_limit_interval_usec, message, flags, error);
if (streq(name, "LogRateLimitBurst"))
return bus_set_transient_unsigned(u, name, &c->log_rate_limit_burst, message, flags, error);
if (streq(name, "Personality"))
return bus_set_transient_personality(u, name, &c->personality, message, flags, error);

View File

@ -3746,6 +3746,9 @@ void exec_context_done(ExecContext *c) {
exec_context_free_log_extra_fields(c);
c->log_rate_limit_interval_usec = 0;
c->log_rate_limit_burst = 0;
c->stdin_data = mfree(c->stdin_data);
c->stdin_data_size = 0;
}
@ -4227,6 +4230,17 @@ void exec_context_dump(const ExecContext *c, FILE* f, const char *prefix) {
fprintf(f, "%sLogLevelMax: %s\n", prefix, strna(t));
}
if (c->log_rate_limit_interval_usec > 0) {
char buf_timespan[FORMAT_TIMESPAN_MAX];
fprintf(f,
"%sLogRateLimitIntervalSec: %s\n",
prefix, format_timespan(buf_timespan, sizeof(buf_timespan), c->log_rate_limit_interval_usec, USEC_PER_SEC));
}
if (c->log_rate_limit_burst > 0)
fprintf(f, "%sLogRateLimitBurst: %u\n", prefix, c->log_rate_limit_burst);
if (c->n_log_extra_fields > 0) {
size_t j;

View File

@ -225,6 +225,9 @@ struct ExecContext {
struct iovec* log_extra_fields;
size_t n_log_extra_fields;
usec_t log_rate_limit_interval_usec;
unsigned log_rate_limit_burst;
bool cpu_sched_reset_on_fork;
bool non_blocking;
bool private_tmp;

View File

@ -57,6 +57,8 @@ $1.SyslogFacility, config_parse_log_facility, 0,
$1.SyslogLevel, config_parse_log_level, 0, offsetof($1, exec_context.syslog_priority)
$1.SyslogLevelPrefix, config_parse_bool, 0, offsetof($1, exec_context.syslog_level_prefix)
$1.LogLevelMax, config_parse_log_level, 0, offsetof($1, exec_context.log_level_max)
$1.LogRateLimitIntervalSec, config_parse_sec, 0, offsetof($1, exec_context.log_rate_limit_interval_usec)
$1.LogRateLimitBurst, config_parse_unsigned, 0, offsetof($1, exec_context.log_rate_limit_burst)
$1.LogExtraFields, config_parse_log_extra_fields, 0, offsetof($1, exec_context)
$1.Capabilities, config_parse_warn_compat, DISABLED_LEGACY, offsetof($1, exec_context)
$1.SecureBits, config_parse_exec_secure_bits, 0, offsetof($1, exec_context.secure_bits)

View File

@ -3249,6 +3249,8 @@ int unit_serialize(Unit *u, FILE *f, FDSet *fds, bool serialize_jobs) {
unit_serialize_item(u, f, "exported-invocation-id", yes_no(u->exported_invocation_id));
unit_serialize_item(u, f, "exported-log-level-max", yes_no(u->exported_log_level_max));
unit_serialize_item(u, f, "exported-log-extra-fields", yes_no(u->exported_log_extra_fields));
unit_serialize_item(u, f, "exported-log-rate-limit-interval", yes_no(u->exported_log_rate_limit_interval));
unit_serialize_item(u, f, "exported-log-rate-limit-burst", yes_no(u->exported_log_rate_limit_burst));
unit_serialize_item_format(u, f, "cpu-usage-base", "%" PRIu64, u->cpu_usage_base);
if (u->cpu_usage_last != NSEC_INFINITY)
@ -3524,6 +3526,26 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) {
continue;
} else if (streq(l, "exported-log-rate-limit-interval")) {
r = parse_boolean(v);
if (r < 0)
log_unit_debug(u, "Failed to parse exported log rate limit interval %s, ignoring.", v);
else
u->exported_log_rate_limit_interval = r;
continue;
} else if (streq(l, "exported-log-rate-limit-burst")) {
r = parse_boolean(v);
if (r < 0)
log_unit_debug(u, "Failed to parse exported log rate limit burst %s, ignoring.", v);
else
u->exported_log_rate_limit_burst = r;
continue;
} else if (STR_IN_SET(l, "cpu-usage-base", "cpuacct-usage-base")) {
r = safe_atou64(v, &u->cpu_usage_base);
@ -5273,6 +5295,60 @@ fail:
return r;
}
static int unit_export_log_rate_limit_interval(Unit *u, const ExecContext *c) {
_cleanup_free_ char *buf = NULL;
const char *p;
int r;
assert(u);
assert(c);
if (u->exported_log_rate_limit_interval)
return 0;
if (c->log_rate_limit_interval_usec == 0)
return 0;
p = strjoina("/run/systemd/units/log-rate-limit-interval:", u->id);
if (asprintf(&buf, "%" PRIu64, c->log_rate_limit_interval_usec) < 0)
return log_oom();
r = symlink_atomic(buf, p);
if (r < 0)
return log_unit_debug_errno(u, r, "Failed to create log rate limit interval symlink %s: %m", p);
u->exported_log_rate_limit_interval = true;
return 0;
}
static int unit_export_log_rate_limit_burst(Unit *u, const ExecContext *c) {
_cleanup_free_ char *buf = NULL;
const char *p;
int r;
assert(u);
assert(c);
if (u->exported_log_rate_limit_burst)
return 0;
if (c->log_rate_limit_burst == 0)
return 0;
p = strjoina("/run/systemd/units/log-rate-limit-burst:", u->id);
if (asprintf(&buf, "%u", c->log_rate_limit_burst) < 0)
return log_oom();
r = symlink_atomic(buf, p);
if (r < 0)
return log_unit_debug_errno(u, r, "Failed to create log rate limit burst symlink %s: %m", p);
u->exported_log_rate_limit_burst = true;
return 0;
}
void unit_export_state_files(Unit *u) {
const ExecContext *c;
@ -5306,6 +5382,8 @@ void unit_export_state_files(Unit *u) {
if (c) {
(void) unit_export_log_level_max(u, c);
(void) unit_export_log_extra_fields(u, c);
(void) unit_export_log_rate_limit_interval(u, c);
(void) unit_export_log_rate_limit_burst(u, c);
}
}
@ -5342,6 +5420,20 @@ void unit_unlink_state_files(Unit *u) {
u->exported_log_extra_fields = false;
}
if (u->exported_log_rate_limit_interval) {
p = strjoina("/run/systemd/units/log-rate-limit-interval:", u->id);
(void) unlink(p);
u->exported_log_rate_limit_interval = false;
}
if (u->exported_log_rate_limit_burst) {
p = strjoina("/run/systemd/units/log-rate-limit-burst:", u->id);
(void) unlink(p);
u->exported_log_rate_limit_burst = false;
}
}
int unit_prepare_exec(Unit *u) {

View File

@ -349,6 +349,8 @@ typedef struct Unit {
bool exported_invocation_id:1;
bool exported_log_level_max:1;
bool exported_log_extra_fields:1;
bool exported_log_rate_limit_interval:1;
bool exported_log_rate_limit_burst:1;
/* When writing transient unit files, stores which section we stored last. If < 0, we didn't write any yet. If
* == 0 we are in the [Unit] section, if > 0 we are in the unit type-specific section. */

View File

@ -13,6 +13,7 @@
#include "io-util.h"
#include "journal-util.h"
#include "journald-context.h"
#include "parse-util.h"
#include "process-util.h"
#include "string-util.h"
#include "syslog-util.h"
@ -102,6 +103,8 @@ static int client_context_new(Server *s, pid_t pid, ClientContext **ret) {
c->timestamp = USEC_INFINITY;
c->extra_fields_mtime = NSEC_INFINITY;
c->log_level_max = -1;
c->log_rate_limit_interval = s->rate_limit_interval;
c->log_rate_limit_burst = s->rate_limit_burst;
r = hashmap_put(s->client_contexts, PID_TO_PTR(pid), c);
if (r < 0) {
@ -113,7 +116,8 @@ static int client_context_new(Server *s, pid_t pid, ClientContext **ret) {
return 0;
}
static void client_context_reset(ClientContext *c) {
static void client_context_reset(Server *s, ClientContext *c) {
assert(s);
assert(c);
c->timestamp = USEC_INFINITY;
@ -148,6 +152,9 @@ static void client_context_reset(ClientContext *c) {
c->extra_fields_mtime = NSEC_INFINITY;
c->log_level_max = -1;
c->log_rate_limit_interval = s->rate_limit_interval;
c->log_rate_limit_burst = s->rate_limit_burst;
}
static ClientContext* client_context_free(Server *s, ClientContext *c) {
@ -161,7 +168,7 @@ static ClientContext* client_context_free(Server *s, ClientContext *c) {
if (c->in_lru)
assert_se(prioq_remove(s->client_contexts_lru, c, &c->lru_index) >= 0);
client_context_reset(c);
client_context_reset(s, c);
return mfree(c);
}
@ -424,6 +431,42 @@ static int client_context_read_extra_fields(
return 0;
}
static int client_context_read_log_rate_limit_interval(ClientContext *c) {
_cleanup_free_ char *value = NULL;
const char *p;
int r;
assert(c);
if (!c->unit)
return 0;
p = strjoina("/run/systemd/units/log-rate-limit-interval:", c->unit);
r = readlink_malloc(p, &value);
if (r < 0)
return r;
return safe_atou64(value, &c->log_rate_limit_interval);
}
static int client_context_read_log_rate_limit_burst(ClientContext *c) {
_cleanup_free_ char *value = NULL;
const char *p;
int r;
assert(c);
if (!c->unit)
return 0;
p = strjoina("/run/systemd/units/log-rate-limit-burst:", c->unit);
r = readlink_malloc(p, &value);
if (r < 0)
return r;
return safe_atou(value, &c->log_rate_limit_burst);
}
static void client_context_really_refresh(
Server *s,
ClientContext *c,
@ -450,6 +493,8 @@ static void client_context_really_refresh(
(void) client_context_read_invocation_id(s, c);
(void) client_context_read_log_level_max(s, c);
(void) client_context_read_extra_fields(s, c);
(void) client_context_read_log_rate_limit_interval(c);
(void) client_context_read_log_rate_limit_burst(c);
c->timestamp = timestamp;
@ -480,7 +525,7 @@ void client_context_maybe_refresh(
/* If the data isn't pinned and if the cashed data is older than the upper limit, we flush it out
* entirely. This follows the logic that as long as an entry is pinned the PID reuse is unlikely. */
if (c->n_ref == 0 && c->timestamp + MAX_USEC < timestamp) {
client_context_reset(c);
client_context_reset(s, c);
goto refresh;
}

View File

@ -49,6 +49,9 @@ struct ClientContext {
size_t extra_fields_n_iovec;
void *extra_fields_data;
nsec_t extra_fields_mtime;
usec_t log_rate_limit_interval;
unsigned log_rate_limit_burst;
};
int client_context_get(

View File

@ -39,6 +39,10 @@ struct JournalRateLimitGroup {
JournalRateLimit *parent;
char *id;
/* Interval is stored to keep track of when the group expires */
usec_t interval;
JournalRateLimitPool pools[POOLS_MAX];
uint64_t hash;
@ -47,8 +51,6 @@ struct JournalRateLimitGroup {
};
struct JournalRateLimit {
usec_t interval;
unsigned burst;
JournalRateLimitGroup* buckets[BUCKETS_MAX];
JournalRateLimitGroup *lru, *lru_tail;
@ -58,18 +60,13 @@ struct JournalRateLimit {
uint8_t hash_key[16];
};
JournalRateLimit *journal_rate_limit_new(usec_t interval, unsigned burst) {
JournalRateLimit *journal_rate_limit_new(void) {
JournalRateLimit *r;
assert(interval > 0 || burst == 0);
r = new0(JournalRateLimit, 1);
if (!r)
return NULL;
r->interval = interval;
r->burst = burst;
random_bytes(r->hash_key, sizeof(r->hash_key));
return r;
@ -109,7 +106,7 @@ _pure_ static bool journal_rate_limit_group_expired(JournalRateLimitGroup *g, us
assert(g);
for (i = 0; i < POOLS_MAX; i++)
if (g->pools[i].begin + g->parent->interval >= ts)
if (g->pools[i].begin + g->interval >= ts)
return false;
return true;
@ -126,7 +123,7 @@ static void journal_rate_limit_vacuum(JournalRateLimit *r, usec_t ts) {
journal_rate_limit_group_free(r->lru_tail);
}
static JournalRateLimitGroup* journal_rate_limit_group_new(JournalRateLimit *r, const char *id, usec_t ts) {
static JournalRateLimitGroup* journal_rate_limit_group_new(JournalRateLimit *r, const char *id, usec_t interval, usec_t ts) {
JournalRateLimitGroup *g;
assert(r);
@ -142,6 +139,8 @@ static JournalRateLimitGroup* journal_rate_limit_group_new(JournalRateLimit *r,
g->hash = siphash24_string(g->id, r->hash_key);
g->interval = interval;
journal_rate_limit_vacuum(r, ts);
LIST_PREPEND(bucket, r->buckets[g->hash % BUCKETS_MAX], g);
@ -186,7 +185,7 @@ static unsigned burst_modulate(unsigned burst, uint64_t available) {
return burst;
}
int journal_rate_limit_test(JournalRateLimit *r, const char *id, int priority, uint64_t available) {
int journal_rate_limit_test(JournalRateLimit *r, const char *id, usec_t rl_interval, unsigned rl_burst, int priority, uint64_t available) {
uint64_t h;
JournalRateLimitGroup *g;
JournalRateLimitPool *p;
@ -205,11 +204,6 @@ int journal_rate_limit_test(JournalRateLimit *r, const char *id, int priority, u
if (!r)
return 1;
if (r->interval == 0 || r->burst == 0)
return 1;
burst = burst_modulate(r->burst, available);
ts = now(CLOCK_MONOTONIC);
h = siphash24_string(id, r->hash_key);
@ -220,10 +214,16 @@ int journal_rate_limit_test(JournalRateLimit *r, const char *id, int priority, u
break;
if (!g) {
g = journal_rate_limit_group_new(r, id, ts);
g = journal_rate_limit_group_new(r, id, rl_interval, ts);
if (!g)
return -ENOMEM;
}
} else
g->interval = rl_interval;
if (rl_interval == 0 || rl_burst == 0)
return 1;
burst = burst_modulate(rl_burst, available);
p = &g->pools[priority_map[priority]];
@ -234,7 +234,7 @@ int journal_rate_limit_test(JournalRateLimit *r, const char *id, int priority, u
return 1;
}
if (p->begin + r->interval < ts) {
if (p->begin + rl_interval < ts) {
unsigned s;
s = p->suppressed;

View File

@ -5,6 +5,6 @@
typedef struct JournalRateLimit JournalRateLimit;
JournalRateLimit *journal_rate_limit_new(usec_t interval, unsigned burst);
JournalRateLimit *journal_rate_limit_new(void);
void journal_rate_limit_free(JournalRateLimit *r);
int journal_rate_limit_test(JournalRateLimit *r, const char *id, int priority, uint64_t available);
int journal_rate_limit_test(JournalRateLimit *r, const char *id, usec_t rl_interval, unsigned rl_burst, int priority, uint64_t available);

View File

@ -937,7 +937,7 @@ void server_dispatch_message(
if (c && c->unit) {
(void) determine_space(s, &available, NULL);
rl = journal_rate_limit_test(s->rate_limit, c->unit, priority & LOG_PRIMASK, available);
rl = journal_rate_limit_test(s->rate_limit, c->unit, c->log_rate_limit_interval, c->log_rate_limit_burst, priority & LOG_PRIMASK, available);
if (rl == 0)
return;
@ -1833,7 +1833,7 @@ int server_init(Server *s) {
if (r < 0)
return r;
s->rate_limit = journal_rate_limit_new(s->rate_limit_interval, s->rate_limit_burst);
s->rate_limit = journal_rate_limit_new();
if (!s->rate_limit)
return -ENOMEM;

View File

@ -800,6 +800,14 @@ static int bus_append_execute_property(sd_bus_message *m, const char *field, con
return bus_append_parse_nsec(m, field, eq);
if (STR_IN_SET(field, "LogRateLimitIntervalSec"))
return bus_append_parse_sec_rename(m, field, eq);
if (streq(field, "LogRateLimitBurst"))
return bus_append_safe_atou(m, field, eq);
if (streq(field, "MountFlags"))
return bus_append_mount_propagation_flags_from_string(m, field, eq);

View File

@ -793,6 +793,8 @@ LineMax=
LockPersonality=
LogExtraFields=
LogLevelMax=
LogRateLimitIntervalSec=
LogRateLimitBurst=
LogsDirectory=
LogsDirectoryMode=
MACVLAN=