Merge pull request #4360 from fbuihuu/journald-fix-flush-when-restarting

Journald fix flush when restarting (#4190)
This commit is contained in:
Lennart Poettering 2016-10-20 00:10:08 +02:00 committed by GitHub
commit 45c0de1f3c
4 changed files with 201 additions and 163 deletions

View file

@ -23,14 +23,14 @@ Journal.SyncIntervalSec, config_parse_sec, 0, offsetof(Server, sync_in
Journal.RateLimitInterval, config_parse_sec, 0, offsetof(Server, rate_limit_interval)
Journal.RateLimitIntervalSec,config_parse_sec, 0, offsetof(Server, rate_limit_interval)
Journal.RateLimitBurst, config_parse_unsigned, 0, offsetof(Server, rate_limit_burst)
Journal.SystemMaxUse, config_parse_iec_uint64, 0, offsetof(Server, system_metrics.max_use)
Journal.SystemMaxFileSize, config_parse_iec_uint64, 0, offsetof(Server, system_metrics.max_size)
Journal.SystemKeepFree, config_parse_iec_uint64, 0, offsetof(Server, system_metrics.keep_free)
Journal.SystemMaxFiles, config_parse_uint64, 0, offsetof(Server, system_metrics.n_max_files)
Journal.RuntimeMaxUse, config_parse_iec_uint64, 0, offsetof(Server, runtime_metrics.max_use)
Journal.RuntimeMaxFileSize, config_parse_iec_uint64, 0, offsetof(Server, runtime_metrics.max_size)
Journal.RuntimeKeepFree, config_parse_iec_uint64, 0, offsetof(Server, runtime_metrics.keep_free)
Journal.RuntimeMaxFiles, config_parse_uint64, 0, offsetof(Server, runtime_metrics.n_max_files)
Journal.SystemMaxUse, config_parse_iec_uint64, 0, offsetof(Server, system_storage.metrics.max_use)
Journal.SystemMaxFileSize, config_parse_iec_uint64, 0, offsetof(Server, system_storage.metrics.max_size)
Journal.SystemKeepFree, config_parse_iec_uint64, 0, offsetof(Server, system_storage.metrics.keep_free)
Journal.SystemMaxFiles, config_parse_uint64, 0, offsetof(Server, system_storage.metrics.n_max_files)
Journal.RuntimeMaxUse, config_parse_iec_uint64, 0, offsetof(Server, runtime_storage.metrics.max_use)
Journal.RuntimeMaxFileSize, config_parse_iec_uint64, 0, offsetof(Server, runtime_storage.metrics.max_size)
Journal.RuntimeKeepFree, config_parse_iec_uint64, 0, offsetof(Server, runtime_storage.metrics.keep_free)
Journal.RuntimeMaxFiles, config_parse_uint64, 0, offsetof(Server, runtime_storage.metrics.n_max_files)
Journal.MaxRetentionSec, config_parse_sec, 0, offsetof(Server, max_retention_usec)
Journal.MaxFileSec, config_parse_sec, 0, offsetof(Server, max_file_usec)
Journal.ForwardToSyslog, config_parse_bool, 0, offsetof(Server, forward_to_syslog)

View file

@ -86,48 +86,24 @@
/* The period to insert between posting changes for coalescing */
#define POST_CHANGE_TIMER_INTERVAL_USEC (250*USEC_PER_MSEC)
static int determine_space_for(
Server *s,
JournalMetrics *metrics,
const char *path,
const char *name,
bool verbose,
bool patch_min_use,
uint64_t *available,
uint64_t *limit) {
uint64_t sum = 0, ss_avail, avail;
static int determine_path_usage(Server *s, const char *path, uint64_t *ret_used, uint64_t *ret_free) {
_cleanup_closedir_ DIR *d = NULL;
struct dirent *de;
struct statvfs ss;
const char *p;
usec_t ts;
assert(s);
assert(metrics);
assert(path);
assert(name);
assert(ret_used);
assert(ret_free);
ts = now(CLOCK_MONOTONIC);
if (!verbose && s->cached_space_timestamp + RECHECK_SPACE_USEC > ts) {
if (available)
*available = s->cached_space_available;
if (limit)
*limit = s->cached_space_limit;
return 0;
}
p = strjoina(path, SERVER_MACHINE_ID(s));
d = opendir(p);
d = opendir(path);
if (!d)
return log_full_errno(errno == ENOENT ? LOG_DEBUG : LOG_ERR, errno, "Failed to open %s: %m", p);
return log_full_errno(errno == ENOENT ? LOG_DEBUG : LOG_ERR,
errno, "Failed to open %s: %m", path);
if (fstatvfs(dirfd(d), &ss) < 0)
return log_error_errno(errno, "Failed to fstatvfs(%s): %m", p);
return log_error_errno(errno, "Failed to fstatvfs(%s): %m", path);
*ret_free = ss.f_bsize * ss.f_bavail;
*ret_used = 0;
FOREACH_DIRENT_ALL(de, d, break) {
struct stat st;
@ -136,88 +112,127 @@ static int determine_space_for(
continue;
if (fstatat(dirfd(d), de->d_name, &st, AT_SYMLINK_NOFOLLOW) < 0) {
log_debug_errno(errno, "Failed to stat %s/%s, ignoring: %m", p, de->d_name);
log_debug_errno(errno, "Failed to stat %s/%s, ignoring: %m", path, de->d_name);
continue;
}
if (!S_ISREG(st.st_mode))
continue;
sum += (uint64_t) st.st_blocks * 512UL;
*ret_used += (uint64_t) st.st_blocks * 512UL;
}
/* If requested, then let's bump the min_use limit to the
* current usage on disk. We do this when starting up and
* first opening the journal files. This way sudden spikes in
* disk usage will not cause journald to vacuum files without
* bounds. Note that this means that only a restart of
* journald will make it reset this value. */
if (patch_min_use)
metrics->min_use = MAX(metrics->min_use, sum);
ss_avail = ss.f_bsize * ss.f_bavail;
avail = LESS_BY(ss_avail, metrics->keep_free);
s->cached_space_limit = MIN(MAX(sum + avail, metrics->min_use), metrics->max_use);
s->cached_space_available = LESS_BY(s->cached_space_limit, sum);
s->cached_space_timestamp = ts;
if (verbose) {
char fb1[FORMAT_BYTES_MAX], fb2[FORMAT_BYTES_MAX], fb3[FORMAT_BYTES_MAX],
fb4[FORMAT_BYTES_MAX], fb5[FORMAT_BYTES_MAX], fb6[FORMAT_BYTES_MAX];
format_bytes(fb1, sizeof(fb1), sum);
format_bytes(fb2, sizeof(fb2), metrics->max_use);
format_bytes(fb3, sizeof(fb3), metrics->keep_free);
format_bytes(fb4, sizeof(fb4), ss_avail);
format_bytes(fb5, sizeof(fb5), s->cached_space_limit);
format_bytes(fb6, sizeof(fb6), s->cached_space_available);
server_driver_message(s, SD_MESSAGE_JOURNAL_USAGE,
LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
name, path, fb1, fb5, fb6),
"JOURNAL_NAME=%s", name,
"JOURNAL_PATH=%s", path,
"CURRENT_USE=%"PRIu64, sum,
"CURRENT_USE_PRETTY=%s", fb1,
"MAX_USE=%"PRIu64, metrics->max_use,
"MAX_USE_PRETTY=%s", fb2,
"DISK_KEEP_FREE=%"PRIu64, metrics->keep_free,
"DISK_KEEP_FREE_PRETTY=%s", fb3,
"DISK_AVAILABLE=%"PRIu64, ss_avail,
"DISK_AVAILABLE_PRETTY=%s", fb4,
"LIMIT=%"PRIu64, s->cached_space_limit,
"LIMIT_PRETTY=%s", fb5,
"AVAILABLE=%"PRIu64, s->cached_space_available,
"AVAILABLE_PRETTY=%s", fb6,
NULL);
}
if (available)
*available = s->cached_space_available;
if (limit)
*limit = s->cached_space_limit;
return 1;
return 0;
}
static int determine_space(Server *s, bool verbose, bool patch_min_use, uint64_t *available, uint64_t *limit) {
static void cache_space_invalidate(JournalStorageSpace *space) {
memset(space, 0, sizeof(*space));
}
static int cache_space_refresh(Server *s, JournalStorage *storage) {
_cleanup_closedir_ DIR *d = NULL;
JournalStorageSpace *space;
JournalMetrics *metrics;
const char *path, *name;
uint64_t vfs_used, vfs_avail, avail;
usec_t ts;
int r;
assert(s);
if (s->system_journal) {
path = "/var/log/journal/";
metrics = &s->system_metrics;
name = "System journal";
} else {
path = "/run/log/journal/";
metrics = &s->runtime_metrics;
name = "Runtime journal";
}
metrics = &storage->metrics;
space = &storage->space;
return determine_space_for(s, metrics, path, name, verbose, patch_min_use, available, limit);
ts = now(CLOCK_MONOTONIC);
if (space->timestamp + RECHECK_SPACE_USEC > ts)
return 0;
r = determine_path_usage(s, storage->path, &vfs_used, &vfs_avail);
if (r < 0)
return r;
space->vfs_used = vfs_used;
space->vfs_available = vfs_avail;
avail = LESS_BY(vfs_avail, metrics->keep_free);
space->limit = MIN(MAX(vfs_used + avail, metrics->min_use), metrics->max_use);
space->available = LESS_BY(space->limit, vfs_used);
space->timestamp = ts;
return 1;
}
static void patch_min_use(JournalStorage *storage) {
assert(storage);
/* Let's bump the min_use limit to the current usage on disk. We do
* this when starting up and first opening the journal files. This way
* sudden spikes in disk usage will not cause journald to vacuum files
* without bounds. Note that this means that only a restart of journald
* will make it reset this value. */
storage->metrics.min_use = MAX(storage->metrics.min_use, storage->space.vfs_used);
}
static int determine_space(Server *s, uint64_t *available, uint64_t *limit) {
JournalStorage *js;
int r;
assert(s);
js = s->system_journal ? &s->system_storage : &s->runtime_storage;
r = cache_space_refresh(s, js);
if (r >= 0) {
if (available)
*available = js->space.available;
if (limit)
*limit = js->space.limit;
}
return r;
}
void server_space_usage_message(Server *s, JournalStorage *storage) {
char fb1[FORMAT_BYTES_MAX], fb2[FORMAT_BYTES_MAX], fb3[FORMAT_BYTES_MAX],
fb4[FORMAT_BYTES_MAX], fb5[FORMAT_BYTES_MAX], fb6[FORMAT_BYTES_MAX];
JournalMetrics *metrics;
assert(s);
if (!storage)
storage = s->system_journal ? &s->system_storage : &s->runtime_storage;
if (cache_space_refresh(s, storage) < 0)
return;
metrics = &storage->metrics;
format_bytes(fb1, sizeof(fb1), storage->space.vfs_used);
format_bytes(fb2, sizeof(fb2), metrics->max_use);
format_bytes(fb3, sizeof(fb3), metrics->keep_free);
format_bytes(fb4, sizeof(fb4), storage->space.vfs_available);
format_bytes(fb5, sizeof(fb5), storage->space.limit);
format_bytes(fb6, sizeof(fb6), storage->space.available);
server_driver_message(s, SD_MESSAGE_JOURNAL_USAGE,
LOG_MESSAGE("%s (%s) is %s, max %s, %s free.",
storage->name, storage->path, fb1, fb5, fb6),
"JOURNAL_NAME=%s", storage->name,
"JOURNAL_PATH=%s", storage->path,
"CURRENT_USE=%"PRIu64, storage->space.vfs_used,
"CURRENT_USE_PRETTY=%s", fb1,
"MAX_USE=%"PRIu64, metrics->max_use,
"MAX_USE_PRETTY=%s", fb2,
"DISK_KEEP_FREE=%"PRIu64, metrics->keep_free,
"DISK_KEEP_FREE_PRETTY=%s", fb3,
"DISK_AVAILABLE=%"PRIu64, storage->space.vfs_available,
"DISK_AVAILABLE_PRETTY=%s", fb4,
"LIMIT=%"PRIu64, storage->space.limit,
"LIMIT_PRETTY=%s", fb5,
"AVAILABLE=%"PRIu64, storage->space.available,
"AVAILABLE_PRETTY=%s", fb6,
NULL);
}
static void server_add_acls(JournalFile *f, uid_t uid) {
@ -290,14 +305,14 @@ static int system_journal_open(Server *s, bool flush_requested) {
if (s->storage == STORAGE_PERSISTENT)
(void) mkdir_p("/var/log/journal/", 0755);
fn = strjoina("/var/log/journal/", SERVER_MACHINE_ID(s));
(void) mkdir(fn, 0755);
(void) mkdir(s->system_storage.path, 0755);
fn = strjoina(fn, "/system.journal");
r = open_journal(s, true, fn, O_RDWR|O_CREAT, s->seal, &s->system_metrics, &s->system_journal);
fn = strjoina(s->system_storage.path, "/system.journal");
r = open_journal(s, true, fn, O_RDWR|O_CREAT, s->seal, &s->system_storage.metrics, &s->system_journal);
if (r >= 0) {
server_add_acls(s->system_journal, 0);
(void) determine_space_for(s, &s->system_metrics, "/var/log/journal/", "System journal", true, true, NULL, NULL);
(void) cache_space_refresh(s, &s->system_storage);
patch_min_use(&s->system_storage);
} else if (r < 0) {
if (r != -ENOENT && r != -EROFS)
log_warning_errno(r, "Failed to open system journal: %m");
@ -319,7 +334,7 @@ static int system_journal_open(Server *s, bool flush_requested) {
if (!s->runtime_journal &&
(s->storage != STORAGE_NONE)) {
fn = strjoina("/run/log/journal/", SERVER_MACHINE_ID(s), "/system.journal");
fn = strjoina(s->runtime_storage.path, "/system.journal");
if (s->system_journal) {
@ -327,7 +342,7 @@ static int system_journal_open(Server *s, bool flush_requested) {
* if it already exists, so that we can flush
* it into the system journal */
r = open_journal(s, false, fn, O_RDWR, false, &s->runtime_metrics, &s->runtime_journal);
r = open_journal(s, false, fn, O_RDWR, false, &s->runtime_storage.metrics, &s->runtime_journal);
if (r < 0) {
if (r != -ENOENT)
log_warning_errno(r, "Failed to open runtime journal: %m");
@ -344,14 +359,15 @@ static int system_journal_open(Server *s, bool flush_requested) {
(void) mkdir("/run/log/journal", 0755);
(void) mkdir_parents(fn, 0750);
r = open_journal(s, true, fn, O_RDWR|O_CREAT, false, &s->runtime_metrics, &s->runtime_journal);
r = open_journal(s, true, fn, O_RDWR|O_CREAT, false, &s->runtime_storage.metrics, &s->runtime_journal);
if (r < 0)
return log_error_errno(r, "Failed to open runtime journal: %m");
}
if (s->runtime_journal) {
server_add_acls(s->runtime_journal, 0);
(void) determine_space_for(s, &s->runtime_metrics, "/run/log/journal/", "Runtime journal", true, true, NULL, NULL);
(void) cache_space_refresh(s, &s->runtime_storage);
patch_min_use(&s->runtime_storage);
}
}
@ -407,7 +423,7 @@ static JournalFile* find_journal(Server *s, uid_t uid) {
(void) journal_file_close(f);
}
r = open_journal(s, true, p, O_RDWR|O_CREAT, s->seal, &s->system_metrics, &f);
r = open_journal(s, true, p, O_RDWR|O_CREAT, s->seal, &s->system_storage.metrics, &f);
if (r < 0)
return s->system_journal;
@ -501,50 +517,38 @@ void server_sync(Server *s) {
s->sync_scheduled = false;
}
static void do_vacuum(
Server *s,
JournalFile *f,
JournalMetrics *metrics,
const char *path,
const char *name,
bool verbose,
bool patch_min_use) {
static void do_vacuum(Server *s, JournalStorage *storage, bool verbose) {
const char *p;
uint64_t limit;
int r;
assert(s);
assert(metrics);
assert(path);
assert(name);
assert(storage);
if (!f)
return;
(void) cache_space_refresh(s, storage);
p = strjoina(path, SERVER_MACHINE_ID(s));
if (verbose)
server_space_usage_message(s, storage);
limit = metrics->max_use;
(void) determine_space_for(s, metrics, path, name, verbose, patch_min_use, NULL, &limit);
r = journal_directory_vacuum(p, limit, metrics->n_max_files, s->max_retention_usec, &s->oldest_file_usec, verbose);
r = journal_directory_vacuum(storage->path, storage->space.limit,
storage->metrics.n_max_files, s->max_retention_usec,
&s->oldest_file_usec, verbose);
if (r < 0 && r != -ENOENT)
log_warning_errno(r, "Failed to vacuum %s, ignoring: %m", p);
log_warning_errno(r, "Failed to vacuum %s, ignoring: %m", storage->path);
cache_space_invalidate(&storage->space);
}
int server_vacuum(Server *s, bool verbose, bool patch_min_use) {
int server_vacuum(Server *s, bool verbose) {
assert(s);
log_debug("Vacuuming...");
s->oldest_file_usec = 0;
do_vacuum(s, s->system_journal, &s->system_metrics, "/var/log/journal/", "System journal", verbose, patch_min_use);
do_vacuum(s, s->runtime_journal, &s->runtime_metrics, "/run/log/journal/", "Runtime journal", verbose, patch_min_use);
s->cached_space_limit = 0;
s->cached_space_available = 0;
s->cached_space_timestamp = 0;
if (s->system_journal)
do_vacuum(s, &s->system_storage, verbose);
if (s->runtime_journal)
do_vacuum(s, &s->runtime_storage, verbose);
return 0;
}
@ -676,7 +680,7 @@ static void write_to_journal(Server *s, uid_t uid, struct iovec *iovec, unsigned
if (rotate) {
server_rotate(s);
server_vacuum(s, false, false);
server_vacuum(s, false);
vacuumed = true;
f = find_journal(s, uid);
@ -698,7 +702,7 @@ static void write_to_journal(Server *s, uid_t uid, struct iovec *iovec, unsigned
}
server_rotate(s);
server_vacuum(s, false, false);
server_vacuum(s, false);
f = find_journal(s, uid);
if (!f)
@ -1165,7 +1169,7 @@ void server_dispatch_message(
}
}
(void) determine_space(s, false, false, &available, NULL);
(void) determine_space(s, &available, NULL);
rl = journal_rate_limit_test(s->rate_limit, path, priority & LOG_PRIMASK, available);
if (rl == 0)
return;
@ -1241,7 +1245,7 @@ int server_flush_to_var(Server *s) {
}
server_rotate(s);
server_vacuum(s, false, false);
server_vacuum(s, false);
if (!s->system_journal) {
log_notice("Didn't flush runtime journal since rotation of system journal wasn't successful.");
@ -1410,12 +1414,13 @@ static int dispatch_sigusr1(sd_event_source *es, const struct signalfd_siginfo *
(void) server_flush_to_var(s);
server_sync(s);
server_vacuum(s, false, false);
server_vacuum(s, false);
r = touch("/run/systemd/journal/flushed");
if (r < 0)
log_warning_errno(r, "Failed to touch /run/systemd/journal/flushed, ignoring: %m");
server_space_usage_message(s, NULL);
return 0;
}
@ -1427,7 +1432,12 @@ static int dispatch_sigusr2(sd_event_source *es, const struct signalfd_siginfo *
log_info("Received request to rotate journal from PID " PID_FMT, si->ssi_pid);
server_rotate(s);
server_vacuum(s, true, true);
server_vacuum(s, true);
if (s->system_journal)
patch_min_use(&s->system_storage);
if (s->runtime_journal)
patch_min_use(&s->runtime_storage);
/* Let clients know when the most recent rotation happened. */
r = write_timestamp_file_atomic("/run/systemd/journal/rotated", now(CLOCK_MONOTONIC));
@ -1872,8 +1882,8 @@ int server_init(Server *s) {
s->max_level_console = LOG_INFO;
s->max_level_wall = LOG_EMERG;
journal_reset_metrics(&s->system_metrics);
journal_reset_metrics(&s->runtime_metrics);
journal_reset_metrics(&s->system_storage.metrics);
journal_reset_metrics(&s->runtime_storage.metrics);
server_parse_config_file(s);
server_parse_proc_cmdline(s);
@ -2026,6 +2036,14 @@ int server_init(Server *s) {
server_cache_boot_id(s);
server_cache_machine_id(s);
s->runtime_storage.name = "Runtime journal";
s->system_storage.name = "System journal";
s->runtime_storage.path = strjoin("/run/log/journal/", SERVER_MACHINE_ID(s), NULL);
s->system_storage.path = strjoin("/var/log/journal/", SERVER_MACHINE_ID(s), NULL);
if (!s->runtime_storage.path || !s->system_storage.path)
return -ENOMEM;
(void) server_connect_notify(s);
return system_journal_open(s, false);

View file

@ -49,6 +49,24 @@ typedef enum SplitMode {
_SPLIT_INVALID = -1
} SplitMode;
typedef struct JournalStorageSpace {
usec_t timestamp;
uint64_t available;
uint64_t limit;
uint64_t vfs_used; /* space used by journal files */
uint64_t vfs_available;
} JournalStorageSpace;
typedef struct JournalStorage {
const char *name;
const char *path;
JournalMetrics metrics;
JournalStorageSpace space;
} JournalStorage;
struct Server {
int syslog_fd;
int native_fd;
@ -89,8 +107,8 @@ struct Server {
usec_t rate_limit_interval;
unsigned rate_limit_burst;
JournalMetrics runtime_metrics;
JournalMetrics system_metrics;
JournalStorage runtime_storage;
JournalStorage system_storage;
bool compress;
bool seal;
@ -103,10 +121,6 @@ struct Server {
unsigned n_forward_syslog_missed;
usec_t last_warn_forward_syslog_missed;
uint64_t cached_space_available;
uint64_t cached_space_limit;
usec_t cached_space_timestamp;
uint64_t var_available_timestamp;
usec_t max_retention_usec;
@ -180,9 +194,10 @@ SplitMode split_mode_from_string(const char *s) _pure_;
int server_init(Server *s);
void server_done(Server *s);
void server_sync(Server *s);
int server_vacuum(Server *s, bool verbose, bool patch_min_use);
int server_vacuum(Server *s, bool verbose);
void server_rotate(Server *s);
int server_schedule_sync(Server *s, int priority);
int server_flush_to_var(Server *s);
void server_maybe_append_tags(Server *s);
int server_process_datagram(sd_event_source *es, int fd, uint32_t revents, void *userdata);
void server_space_usage_message(Server *s, JournalStorage *storage);

View file

@ -51,7 +51,7 @@ int main(int argc, char *argv[]) {
if (r < 0)
goto finish;
server_vacuum(&server, false, false);
server_vacuum(&server, false);
server_flush_to_var(&server);
server_flush_dev_kmsg(&server);
@ -60,6 +60,11 @@ int main(int argc, char *argv[]) {
LOG_MESSAGE("Journal started"),
NULL);
/* Make sure to send the usage message *after* flushing the
* journal so entries from the runtime journals are ordered
* before this message. See #4190 for some details. */
server_space_usage_message(&server, NULL);
for (;;) {
usec_t t = USEC_INFINITY, n;
@ -77,7 +82,7 @@ int main(int argc, char *argv[]) {
if (server.oldest_file_usec + server.max_retention_usec < n) {
log_info("Retention time reached.");
server_rotate(&server);
server_vacuum(&server, false, false);
server_vacuum(&server, false);
continue;
}