Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core: implement per unit journal rate limiting #10308

Merged
merged 1 commit into from Oct 18, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
3 changes: 2 additions & 1 deletion catalog/systemd.catalog.in
Expand Up @@ -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
Expand Down
2 changes: 2 additions & 0 deletions docs/TRANSIENT-SETTINGS.md
Expand Up @@ -135,6 +135,8 @@ All execution-related settings are available for transient units.
✓ SyslogLevelPrefix=
✓ LogLevelMax=
✓ LogExtraFields=
✓ LogRateLimitIntervalSec=
✓ LogRateLimitBurst=
✓ SecureBits=
✓ CapabilityBoundingSet=
✓ AmbientCapabilities=
Expand Down
8 changes: 7 additions & 1 deletion man/journald.conf.xml
Expand Up @@ -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>
Expand Down
16 changes: 16 additions & 0 deletions man/systemd.exec.xml
Expand Up @@ -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>

Expand Down
8 changes: 8 additions & 0 deletions src/core/dbus-execute.c
Expand Up @@ -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),
Expand Down Expand Up @@ -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);

Expand Down
14 changes: 14 additions & 0 deletions src/core/execute.c
Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;

Expand Down
3 changes: 3 additions & 0 deletions src/core/execute.h
Expand Up @@ -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;
Expand Down
2 changes: 2 additions & 0 deletions src/core/load-fragment-gperf.gperf.m4
Expand Up @@ -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)
Expand Down
92 changes: 92 additions & 0 deletions src/core/unit.c
Expand Up @@ -3245,6 +3245,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)
Expand Down Expand Up @@ -3520,6 +3522,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);
Expand Down Expand Up @@ -5269,6 +5291,60 @@ static int unit_export_log_extra_fields(Unit *u, const ExecContext *c) {
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;

Expand Down Expand Up @@ -5302,6 +5378,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);
}
}

Expand Down Expand Up @@ -5338,6 +5416,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) {
Expand Down
2 changes: 2 additions & 0 deletions src/core/unit.h
Expand Up @@ -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. */
Expand Down
51 changes: 48 additions & 3 deletions src/journal/journald-context.c
Expand Up @@ -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"
Expand Down Expand Up @@ -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) {
Expand All @@ -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;
Expand Down Expand Up @@ -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) {
Expand All @@ -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);
}
Expand Down Expand Up @@ -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,
Expand All @@ -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;

Expand Down Expand Up @@ -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;
}

Expand Down
3 changes: 3 additions & 0 deletions src/journal/journald-context.h
Expand Up @@ -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(
Expand Down