base/SOURCES/0610-sd-journal-properly-handle-inotify-queue-overflow.patch

From 7204e7f9ea3067bda7e5658a06e91b67c736f8ab Mon Sep 17 00:00:00 2001
From: Lennart Poettering <lennart@poettering.net>
Date: Mon, 12 Feb 2018 16:14:58 +0100
Subject: [PATCH] sd-journal: properly handle inotify queue overflow

This adds proper handling of IN_Q_OVERFLOW: when the inotify queue runs
over we'll reiterate all directories we are looking at. At the same time
we'll mark all files and directories we encounter that way with a
generation counter we first increased. All files and directories not
marked like this are then unloaded.

With this logic we do the best when the inotify queue overflows: we
synchronize our in-memory state again with what's on disk.  This
contains some refactoring of the directory logic, to share more code
between uuid directories and "root" directories and generally make
things a bit more readable by splitting things up into smaller bits.

See: #7998 #8032

(cherry-picked from commit 858749f7312bd0adb5433075a92e1c35a2fb56ac)

Resolves: #1540538
---
 src/journal/journal-file.h     |   2 +
 src/journal/journal-internal.h |   2 +
 src/journal/sd-journal.c       | 237 ++++++++++++++++++++++++++++++++---------
 src/shared/path-util.c         |  14 +++
 src/shared/path-util.h         |   2 +
 5 files changed, 206 insertions(+), 51 deletions(-)

diff --git a/src/journal/journal-file.h b/src/journal/journal-file.h
index c74ad5fc5..dd8ef52d2 100644
--- a/src/journal/journal-file.h
+++ b/src/journal/journal-file.h
@@ -121,6 +121,8 @@ typedef struct JournalFile {
 
         void *fsprg_seed;
         size_t fsprg_seed_size;
+
+        unsigned last_seen_generation;
 #endif
 } JournalFile;
 
diff --git a/src/journal/journal-internal.h b/src/journal/journal-internal.h
index eb23ac28a..999e9d8cb 100644
--- a/src/journal/journal-internal.h
+++ b/src/journal/journal-internal.h
@@ -81,6 +81,7 @@ struct Directory {
         char *path;
         int wd;
         bool is_root;
+        unsigned last_seen_generation;
 };
 
 struct sd_journal {
@@ -102,6 +103,7 @@ struct sd_journal {
         int inotify_fd;
         unsigned current_invalidate_counter, last_invalidate_counter;
         usec_t last_process_usec;
+        unsigned generation;
 
         char *unique_field;
         JournalFile *unique_file;
diff --git a/src/journal/sd-journal.c b/src/journal/sd-journal.c
index 14b65cfed..9186f5188 100644
--- a/src/journal/sd-journal.c
+++ b/src/journal/sd-journal.c
@@ -1229,8 +1229,16 @@ static int add_any_file(sd_journal *j, const char *path) {
         assert(j);
         assert(path);
 
-        if (ordered_hashmap_get(j->files, path))
-                return 0;
+        if (path) {
+                f = ordered_hashmap_get(j->files, path);
+                if (f) {
+                        /* Mark this file as seen in this generation. This is used to GC old files in
+                         * process_q_overflow() to detect journal files that are still and discern them from those who
+                         * are gone. */
+                        f->last_seen_generation = j->generation;
+                        return 0;
+                }
+        }
 
         if (ordered_hashmap_size(j->files) >= JOURNAL_FILES_MAX) {
                 log_debug("Too many open journal files, not adding %s.", path);
@@ -1252,6 +1260,8 @@ static int add_any_file(sd_journal *j, const char *path) {
                 goto fail;
         }
 
+        f->last_seen_generation = j->generation;
+
         log_debug("File %s added.", f->path);
 
         check_network(j, f->fd);
@@ -1346,10 +1356,96 @@ static int dirname_is_machine_id(const char *fn) {
         return sd_id128_equal(id, machine);
 }
 
+static bool dirent_is_journal_file(const struct dirent *de) {
+        assert(de);
+
+        if (!IN_SET(de->d_type, DT_REG, DT_LNK, DT_UNKNOWN))
+                return false;
+
+        return endswith(de->d_name, ".journal") ||
+                endswith(de->d_name, ".journal~");
+}
+
+static bool dirent_is_id128_subdir(const struct dirent *de) {
+        assert(de);
+
+        if (!IN_SET(de->d_type, DT_DIR, DT_LNK, DT_UNKNOWN))
+                return false;
+
+        return id128_is_valid(de->d_name);
+}
+
+static int directory_open(sd_journal *j, const char *path, DIR **ret) {
+        DIR *d;
+
+        assert(j);
+        assert(path);
+        assert(ret);
+
+        d = opendir(path);
+        if (!d)
+                return -errno;
+
+        *ret = d;
+        return 0;
+}
+
+static int add_directory(sd_journal *j, const char *prefix, const char *dirname);
+
+static void directory_enumerate(sd_journal *j, Directory *m, DIR *d) {
+        struct dirent *de;
+
+        assert(j);
+        assert(m);
+        assert(d);
+
+        FOREACH_DIRENT_ALL(de, d, goto fail) {
+                if (dirent_is_journal_file(de))
+                        (void) add_file(j, m->path, de->d_name);
+
+                if (m->is_root && dirent_is_id128_subdir(de))
+                        (void) add_directory(j, m->path, de->d_name);
+        }
+
+        return;
+
+fail:
+        log_debug_errno(errno, "Failed to enumerate directory %s, ignoring: %m", m->path);
+}
+
+static void directory_watch(sd_journal *j, Directory *m, int fd, uint32_t mask) {
+        int r;
+
+        assert(j);
+        assert(m);
+        assert(fd >= 0);
+
+        /* Watch this directory if that's enabled and if it not being watched yet. */
+
+        if (m->wd > 0) /* Already have a watch? */
+                return;
+        if (j->inotify_fd < 0) /* Not watching at all? */
+                return;
+
+        m->wd = inotify_add_watch_fd(j->inotify_fd, fd, mask);
+        if (m->wd < 0) {
+                log_debug_errno(errno, "Failed to watch journal directory '%s', ignoring: %m", m->path);
+                return;
+        }
+
+        r = hashmap_put(j->directories_by_wd, INT_TO_PTR(m->wd), m);
+        if (r == -EEXIST)
+                log_debug_errno(r, "Directory '%s' already being watched under a different path, ignoring: %m", m->path);
+        if (r < 0) {
+                log_debug_errno(r, "Failed to add watch for journal directory '%s' to hashmap, ignoring: %m", m->path);
+                (void) inotify_rm_watch(j->inotify_fd, m->wd);
+                m->wd = -1;
+        }
+}
+
 static int add_directory(sd_journal *j, const char *prefix, const char *dirname) {
         _cleanup_free_ char *path = NULL;
         _cleanup_closedir_ DIR *d = NULL;
-        struct dirent *de = NULL;
         Directory *m;
         int r, k;
 
@@ -1357,7 +1453,7 @@ static int add_directory(sd_journal *j, const char *prefix, const char *dirname)
         assert(prefix);
         assert(dirname);
 
-        log_debug("Considering %s/%s.", prefix, dirname);
+        log_debug("Considering '%s/%s'.", prefix, dirname);
 
         if ((j->flags & SD_JOURNAL_LOCAL_ONLY) &&
             !(dirname_is_machine_id(dirname) > 0 || path_startswith(prefix, "/run")))
@@ -1369,9 +1465,9 @@ static int add_directory(sd_journal *j, const char *prefix, const char *dirname)
                 goto fail;
         }
 
-        d = opendir(path);
-        if (!d) {
-                r = log_debug_errno(errno, "Failed to open directory %s: %m", path);
+        r = directory_open(j, path, &d);
+        if (r < 0) {
+                r = log_debug_errno(errno, "Failed to open directory '%s': %m", path);
                 goto fail;
         }
 
@@ -1398,25 +1494,17 @@ static int add_directory(sd_journal *j, const char *prefix, const char *dirname)
                 log_debug("Directory %s added.", m->path);
 
         } else if (m->is_root)
-                return 0;
-
-        if (m->wd <= 0 && j->inotify_fd >= 0) {
-
-                m->wd = inotify_add_watch(j->inotify_fd, m->path,
-                                          IN_CREATE|IN_MOVED_TO|IN_MODIFY|IN_ATTRIB|IN_DELETE|
-                                          IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_MOVED_FROM|
-                                          IN_ONLYDIR);
+                return 0; /* Don't 'downgrade' from root directory */
 
-                if (m->wd > 0 && hashmap_put(j->directories_by_wd, INT_TO_PTR(m->wd), m) < 0)
-                        inotify_rm_watch(j->inotify_fd, m->wd);
-        }
+        m->last_seen_generation = j->generation;
 
-        FOREACH_DIRENT_ALL(de, d, return log_debug_errno(errno, "Failed to read directory %s: %m", m->path)) {
+        directory_watch(j, m, dirfd(d),
+                        IN_CREATE|IN_MOVED_TO|IN_MODIFY|IN_ATTRIB|IN_DELETE|
+                        IN_DELETE_SELF|IN_MOVE_SELF|IN_UNMOUNT|IN_MOVED_FROM|
+                        IN_ONLYDIR);
 
-                if (dirent_is_file_with_suffix(de, ".journal") ||
-                    dirent_is_file_with_suffix(de, ".journal~"))
-                        (void) add_file(j, m->path, de->d_name);
-        }
+        if (!j->no_new_files)
+                directory_enumerate(j, m, d);
 
         check_network(j, dirfd(d));
 
@@ -1432,13 +1520,14 @@ fail:
 
 static int add_root_directory(sd_journal *j, const char *p, bool missing_ok) {
         _cleanup_closedir_ DIR *d = NULL;
-        struct dirent *de;
         Directory *m;
         int r, k;
 
         assert(j);
         assert(p);
 
+        log_debug("Considering root directory '%s'.", p);
+
         if ((j->flags & SD_JOURNAL_RUNTIME_ONLY) &&
             !path_startswith(p, "/run"))
                 return -EINVAL;
@@ -1446,12 +1535,11 @@ static int add_root_directory(sd_journal *j, const char *p, bool missing_ok) {
         if (j->prefix)
                 p = strjoina(j->prefix, p);
 
-        d = opendir(p);
-        if (!d) {
-                if (errno == ENOENT && missing_ok)
-                        return 0;
-
-                r = log_debug_errno(errno, "Failed to open root directory %s: %m", p);
+        r = directory_open(j, p, &d);
+        if (r == -ENOENT && missing_ok)
+                return 0;
+        if (r < 0) {
+                log_debug_errno(r, "Failed to open root directory %s: %m", p);
                 goto fail;
         }
 
@@ -1495,19 +1583,12 @@ static int add_root_directory(sd_journal *j, const char *p, bool missing_ok) {
                         inotify_rm_watch(j->inotify_fd, m->wd);
         }
 
-        if (j->no_new_files)
-                return 0;
-
-        FOREACH_DIRENT_ALL(de, d, return log_debug_errno(errno, "Failed to read directory %s: %m", m->path)) {
-                sd_id128_t id;
+        directory_watch(j, m, dirfd(d),
+                        IN_CREATE|IN_MOVED_TO|IN_MODIFY|IN_ATTRIB|IN_DELETE|
+                        IN_ONLYDIR);
 
-                if (dirent_is_file_with_suffix(de, ".journal") ||
-                    dirent_is_file_with_suffix(de, ".journal~"))
-                        (void) add_file(j, m->path, de->d_name);
-                else if (IN_SET(de->d_type, DT_DIR, DT_LNK, DT_UNKNOWN) &&
-                         sd_id128_from_string(de->d_name, &id) >= 0)
-                        (void) add_directory(j, m->path, de->d_name);
-        }
+        if (!j->no_new_files)
+                directory_enumerate(j, m, d);
 
         check_network(j, dirfd(d));
 
@@ -2068,6 +2149,18 @@ _public_ void sd_journal_restart_data(sd_journal *j) {
         j->current_field = 0;
 }
 
+static int reiterate_all_paths(sd_journal *j) {
+        assert(j);
+
+        if (j->no_new_files)
+                return add_current_paths(j);
+
+        if (j->path)
+                return add_root_directory(j, j->path, true);
+
+        return add_search_paths(j);
+}
+
 _public_ int sd_journal_get_fd(sd_journal *j) {
         int r;
 
@@ -2081,15 +2174,11 @@ _public_ int sd_journal_get_fd(sd_journal *j) {
         if (r < 0)
                 return r;
 
-        /* Iterate through all dirs again, to add them to the
-         * inotify */
-        if (j->no_new_files)
-                r = add_current_paths(j);
-        else if (j->path)
-                r = add_root_directory(j, j->path, true);
-        else
-                r = add_search_paths(j);
-        if (r < 0)
+         log_debug("Reiterating files to get inotify watches established.");
+
+        /* Iterate through all dirs again, to add them to the inotify */
+        r = reiterate_all_paths(j);
+         if (r < 0)
                 return r;
 
         return j->inotify_fd;
@@ -2131,12 +2220,58 @@ _public_ int sd_journal_get_timeout(sd_journal *j, uint64_t *timeout_usec) {
         return 1;
 }
 
+static void process_q_overflow(sd_journal *j) {
+        JournalFile *f;
+        Directory *m;
+        Iterator i;
+
+        assert(j);
+
+        /* When the inotify queue overruns we need to enumerate and re-validate all journal files to bring our list
+         * back in sync with what's on disk. For this we pick a new generation counter value. It'll be assigned to all
+         * journal files we encounter. All journal files and all directories that don't carry it after reenumeration
+         * are subject for unloading. */
+
+        log_debug("Inotify queue overrun, reiterating everything.");
+
+        j->generation++;
+        (void) reiterate_all_paths(j);
+
+        ORDERED_HASHMAP_FOREACH(f, j->files, i) {
+
+                if (f->last_seen_generation == j->generation)
+                        continue;
+
+                log_debug("File '%s' hasn't been seen in this enumeration, removing.", f->path);
+                remove_file_real(j, f);
+        }
+
+        HASHMAP_FOREACH(m, j->directories_by_path, i) {
+
+                if (m->last_seen_generation == j->generation)
+                        continue;
+
+                if (m->is_root) /* Never GC root directories */
+                        continue;
+
+                log_debug("Directory '%s' hasn't been seen in this enumeration, removing.", f->path);
+                remove_directory(j, m);
+        }
+
+        log_debug("Reiteration complete.");
+}
+
 static void process_inotify_event(sd_journal *j, struct inotify_event *e) {
         Directory *d;
 
         assert(j);
         assert(e);
 
+        if (e->mask & IN_Q_OVERFLOW) {
+                process_q_overflow(j);
+                return;
+        }
+
         /* Is this a subdirectory we watch? */
         d = hashmap_get(j->directories_by_wd, INT_TO_PTR(e->wd));
         if (d) {
diff --git a/src/shared/path-util.c b/src/shared/path-util.c
index 5d4de9ec4..fcc591686 100644
--- a/src/shared/path-util.c
+++ b/src/shared/path-util.c
@@ -861,3 +861,17 @@ char *prefix_root(const char *root, const char *path) {
         strcpy(p, path);
         return n;
 }
+
+int inotify_add_watch_fd(int fd, int what, uint32_t mask) {
+        char path[strlen("/proc/self/fd/") + DECIMAL_STR_MAX(int) + 1];
+        int r;
+
+        /* This is like inotify_add_watch(), except that the file to watch is not referenced by a path, but by an fd */
+        xsprintf(path, "/proc/self/fd/%i", what);
+
+        r = inotify_add_watch(fd, path, mask);
+        if (r < 0)
+                return -errno;
+
+        return r;
+}
diff --git a/src/shared/path-util.h b/src/shared/path-util.h
index 34c016229..96490e12b 100644
--- a/src/shared/path-util.h
+++ b/src/shared/path-util.h
@@ -66,6 +66,8 @@ int fsck_exists(const char *fstype);
 
 char *prefix_root(const char *root, const char *path);
 
+int inotify_add_watch_fd(int fd, int what, uint32_t mask);
+
 /* Similar to prefix_root(), but returns an alloca() buffer, or
  * possibly a const pointer into the path parameter */
 #define prefix_roota(root, path)                                        \