]> git.ipfire.org Git - thirdparty/systemd.git/blobdiff - src/journal/journal-file.c
journal: emit debug log about settings only once (or when changed)
[thirdparty/systemd.git] / src / journal / journal-file.c
index 390996a8150d71161317b604cd5b1bacb7edf4b4..f0dd695adbce74983ca838c1b241a45e9ce7e436 100644 (file)
 #include <sys/uio.h>
 #include <unistd.h>
 
+#include "sd-event.h"
+
 #include "alloc-util.h"
 #include "btrfs-util.h"
 #include "chattr-util.h"
 #include "compress.h"
 #include "fd-util.h"
+#include "format-util.h"
 #include "fs-util.h"
 #include "journal-authenticate.h"
 #include "journal-def.h"
 #include "journal-file.h"
 #include "lookup3.h"
-#include "parse-util.h"
+#include "memory-util.h"
 #include "path-util.h"
 #include "random-util.h"
-#include "sd-event.h"
 #include "set.h"
+#include "sort-util.h"
 #include "stat-util.h"
 #include "string-util.h"
 #include "strv.h"
@@ -235,8 +238,10 @@ int journal_file_set_offline(JournalFile *f, bool wait) {
                 sigset_t ss, saved_ss;
                 int k;
 
-                if (sigfillset(&ss) < 0)
-                        return -errno;
+                assert_se(sigfillset(&ss) >= 0);
+                /* Don't block SIGBUS since the offlining thread accesses a memory mapped file.
+                 * Asynchronous SIGBUS signals can safely be handled by either thread. */
+                assert_se(sigdelset(&ss, SIGBUS) >= 0);
 
                 r = pthread_sigmask(SIG_BLOCK, &ss, &saved_ss);
                 if (r > 0)
@@ -335,7 +340,8 @@ bool journal_file_is_offlining(JournalFile *f) {
 }
 
 JournalFile* journal_file_close(JournalFile *f) {
-        assert(f);
+        if (!f)
+                return NULL;
 
 #if HAVE_GCRYPT
         /* Write the final tag */
@@ -352,8 +358,7 @@ JournalFile* journal_file_close(JournalFile *f) {
                 if (sd_event_source_get_enabled(f->post_change_timer, NULL) > 0)
                         journal_file_post_change(f);
 
-                (void) sd_event_source_set_enabled(f->post_change_timer, SD_EVENT_OFF);
-                sd_event_source_unref(f->post_change_timer);
+                sd_event_source_disable_unref(f->post_change_timer);
         }
 
         journal_file_set_offline(f, true);
@@ -565,13 +570,14 @@ static int journal_file_verify_header(JournalFile *f) {
 
                 if (state == STATE_ARCHIVED)
                         return -ESHUTDOWN; /* Already archived */
-                else if (state == STATE_ONLINE) {
-                        log_debug("Journal file %s is already online. Assuming unclean closing.", f->path);
-                        return -EBUSY;
-                } else if (state != STATE_OFFLINE) {
-                        log_debug("Journal file %s has unknown state %i.", f->path, state);
-                        return -EBUSY;
-                }
+                else if (state == STATE_ONLINE)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBUSY),
+                                               "Journal file %s is already online. Assuming unclean closing.",
+                                               f->path);
+                else if (state != STATE_OFFLINE)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBUSY),
+                                               "Journal file %s has unknown state %i.",
+                                               f->path, state);
 
                 if (f->header->field_hash_table_size == 0 || f->header->data_hash_table_size == 0)
                         return -EBADMSG;
@@ -579,10 +585,10 @@ static int journal_file_verify_header(JournalFile *f) {
                 /* Don't permit appending to files from the future. Because otherwise the realtime timestamps wouldn't
                  * be strictly ordered in the entries in the file anymore, and we can't have that since it breaks
                  * bisection. */
-                if (le64toh(f->header->tail_entry_realtime) > now(CLOCK_REALTIME)) {
-                        log_debug("Journal file %s is from the future, refusing to append new data to it that'd be older.", f->path);
-                        return -ETXTBSY;
-                }
+                if (le64toh(f->header->tail_entry_realtime) > now(CLOCK_REALTIME))
+                        return log_debug_errno(SYNTHETIC_ERRNO(ETXTBSY),
+                                               "Journal file %s is from the future, refusing to append new data to it that'd be older.",
+                                               f->path);
         }
 
         f->compress_xz = JOURNAL_HEADER_COMPRESSED_XZ(f->header);
@@ -746,153 +752,124 @@ static int journal_file_check_object(JournalFile *f, uint64_t offset, Object *o)
         switch (o->object.type) {
 
         case OBJECT_DATA: {
-                if ((le64toh(o->data.entry_offset) == 0) ^ (le64toh(o->data.n_entries) == 0)) {
-                        log_debug("Bad n_entries: %"PRIu64": %"PRIu64,
-                                        le64toh(o->data.n_entries), offset);
-                        return -EBADMSG;
-                }
-
-                if (le64toh(o->object.size) - offsetof(DataObject, payload) <= 0) {
-                        log_debug("Bad object size (<= %zu): %"PRIu64": %"PRIu64,
-                              offsetof(DataObject, payload),
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
+                if ((le64toh(o->data.entry_offset) == 0) ^ (le64toh(o->data.n_entries) == 0))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Bad n_entries: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->data.n_entries),
+                                               offset);
+
+                if (le64toh(o->object.size) - offsetof(DataObject, payload) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Bad object size (<= %zu): %" PRIu64 ": %" PRIu64,
+                                               offsetof(DataObject, payload),
+                                               le64toh(o->object.size),
+                                               offset);
 
                 if (!VALID64(le64toh(o->data.next_hash_offset)) ||
                     !VALID64(le64toh(o->data.next_field_offset)) ||
                     !VALID64(le64toh(o->data.entry_offset)) ||
-                    !VALID64(le64toh(o->data.entry_array_offset))) {
-                        log_debug("Invalid offset, next_hash_offset="OFSfmt", next_field_offset="OFSfmt
-                                ", entry_offset="OFSfmt", entry_array_offset="OFSfmt": %"PRIu64,
-                              le64toh(o->data.next_hash_offset),
-                              le64toh(o->data.next_field_offset),
-                              le64toh(o->data.entry_offset),
-                              le64toh(o->data.entry_array_offset),
-                              offset);
-                        return -EBADMSG;
-                }
+                    !VALID64(le64toh(o->data.entry_array_offset)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid offset, next_hash_offset=" OFSfmt ", next_field_offset=" OFSfmt ", entry_offset=" OFSfmt ", entry_array_offset=" OFSfmt ": %" PRIu64,
+                                               le64toh(o->data.next_hash_offset),
+                                               le64toh(o->data.next_field_offset),
+                                               le64toh(o->data.entry_offset),
+                                               le64toh(o->data.entry_array_offset),
+                                               offset);
 
                 break;
         }
 
         case OBJECT_FIELD:
-                if (le64toh(o->object.size) - offsetof(FieldObject, payload) <= 0) {
-                        log_debug(
-                              "Bad field size (<= %zu): %"PRIu64": %"PRIu64,
-                              offsetof(FieldObject, payload),
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
+                if (le64toh(o->object.size) - offsetof(FieldObject, payload) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Bad field size (<= %zu): %" PRIu64 ": %" PRIu64,
+                                               offsetof(FieldObject, payload),
+                                               le64toh(o->object.size),
+                                               offset);
 
                 if (!VALID64(le64toh(o->field.next_hash_offset)) ||
-                    !VALID64(le64toh(o->field.head_data_offset))) {
-                        log_debug(
-                              "Invalid offset, next_hash_offset="OFSfmt
-                              ", head_data_offset="OFSfmt": %"PRIu64,
-                              le64toh(o->field.next_hash_offset),
-                              le64toh(o->field.head_data_offset),
-                              offset);
-                        return -EBADMSG;
-                }
+                    !VALID64(le64toh(o->field.head_data_offset)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid offset, next_hash_offset=" OFSfmt ", head_data_offset=" OFSfmt ": %" PRIu64,
+                                               le64toh(o->field.next_hash_offset),
+                                               le64toh(o->field.head_data_offset),
+                                               offset);
                 break;
 
         case OBJECT_ENTRY:
-                if ((le64toh(o->object.size) - offsetof(EntryObject, items)) % sizeof(EntryItem) != 0) {
-                        log_debug(
-                              "Bad entry size (<= %zu): %"PRIu64": %"PRIu64,
-                              offsetof(EntryObject, items),
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
-
-                if ((le64toh(o->object.size) - offsetof(EntryObject, items)) / sizeof(EntryItem) <= 0) {
-                        log_debug(
-                              "Invalid number items in entry: %"PRIu64": %"PRIu64,
-                              (le64toh(o->object.size) - offsetof(EntryObject, items)) / sizeof(EntryItem),
-                              offset);
-                        return -EBADMSG;
-                }
-
-                if (le64toh(o->entry.seqnum) <= 0) {
-                        log_debug(
-                              "Invalid entry seqnum: %"PRIx64": %"PRIu64,
-                              le64toh(o->entry.seqnum),
-                              offset);
-                        return -EBADMSG;
-                }
-
-                if (!VALID_REALTIME(le64toh(o->entry.realtime))) {
-                        log_debug(
-                              "Invalid entry realtime timestamp: %"PRIu64": %"PRIu64,
-                              le64toh(o->entry.realtime),
-                              offset);
-                        return -EBADMSG;
-                }
-
-                if (!VALID_MONOTONIC(le64toh(o->entry.monotonic))) {
-                        log_debug(
-                              "Invalid entry monotonic timestamp: %"PRIu64": %"PRIu64,
-                              le64toh(o->entry.monotonic),
-                              offset);
-                        return -EBADMSG;
-                }
+                if ((le64toh(o->object.size) - offsetof(EntryObject, items)) % sizeof(EntryItem) != 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Bad entry size (<= %zu): %" PRIu64 ": %" PRIu64,
+                                               offsetof(EntryObject, items),
+                                               le64toh(o->object.size),
+                                               offset);
+
+                if ((le64toh(o->object.size) - offsetof(EntryObject, items)) / sizeof(EntryItem) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid number items in entry: %" PRIu64 ": %" PRIu64,
+                                               (le64toh(o->object.size) - offsetof(EntryObject, items)) / sizeof(EntryItem),
+                                               offset);
+
+                if (le64toh(o->entry.seqnum) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid entry seqnum: %" PRIx64 ": %" PRIu64,
+                                               le64toh(o->entry.seqnum),
+                                               offset);
+
+                if (!VALID_REALTIME(le64toh(o->entry.realtime)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid entry realtime timestamp: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->entry.realtime),
+                                               offset);
+
+                if (!VALID_MONOTONIC(le64toh(o->entry.monotonic)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid entry monotonic timestamp: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->entry.monotonic),
+                                               offset);
 
                 break;
 
         case OBJECT_DATA_HASH_TABLE:
         case OBJECT_FIELD_HASH_TABLE:
                 if ((le64toh(o->object.size) - offsetof(HashTableObject, items)) % sizeof(HashItem) != 0 ||
-                    (le64toh(o->object.size) - offsetof(HashTableObject, items)) / sizeof(HashItem) <= 0) {
-                        log_debug(
-                              "Invalid %s hash table size: %"PRIu64": %"PRIu64,
-                              o->object.type == OBJECT_DATA_HASH_TABLE ? "data" : "field",
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
+                    (le64toh(o->object.size) - offsetof(HashTableObject, items)) / sizeof(HashItem) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid %s hash table size: %" PRIu64 ": %" PRIu64,
+                                               o->object.type == OBJECT_DATA_HASH_TABLE ? "data" : "field",
+                                               le64toh(o->object.size),
+                                               offset);
 
                 break;
 
         case OBJECT_ENTRY_ARRAY:
                 if ((le64toh(o->object.size) - offsetof(EntryArrayObject, items)) % sizeof(le64_t) != 0 ||
-                    (le64toh(o->object.size) - offsetof(EntryArrayObject, items)) / sizeof(le64_t) <= 0) {
-                        log_debug(
-                              "Invalid object entry array size: %"PRIu64": %"PRIu64,
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
-
-                if (!VALID64(le64toh(o->entry_array.next_entry_array_offset))) {
-                        log_debug(
-                              "Invalid object entry array next_entry_array_offset: "OFSfmt": %"PRIu64,
-                              le64toh(o->entry_array.next_entry_array_offset),
-                              offset);
-                        return -EBADMSG;
-                }
+                    (le64toh(o->object.size) - offsetof(EntryArrayObject, items)) / sizeof(le64_t) <= 0)
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid object entry array size: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->object.size),
+                                               offset);
+
+                if (!VALID64(le64toh(o->entry_array.next_entry_array_offset)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid object entry array next_entry_array_offset: " OFSfmt ": %" PRIu64,
+                                               le64toh(o->entry_array.next_entry_array_offset),
+                                               offset);
 
                 break;
 
         case OBJECT_TAG:
-                if (le64toh(o->object.size) != sizeof(TagObject)) {
-                        log_debug(
-                              "Invalid object tag size: %"PRIu64": %"PRIu64,
-                              le64toh(o->object.size),
-                              offset);
-                        return -EBADMSG;
-                }
+                if (le64toh(o->object.size) != sizeof(TagObject))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid object tag size: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->object.size),
+                                               offset);
 
-                if (!VALID_EPOCH(le64toh(o->tag.epoch))) {
-                        log_debug(
-                              "Invalid object tag epoch: %"PRIu64": %"PRIu64,
-                              le64toh(o->tag.epoch),
-                              offset);
-                        return -EBADMSG;
-                }
+                if (!VALID_EPOCH(le64toh(o->tag.epoch)))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid object tag epoch: %" PRIu64 ": %" PRIu64,
+                                               le64toh(o->tag.epoch), offset);
 
                 break;
         }
@@ -911,16 +888,16 @@ int journal_file_move_to_object(JournalFile *f, ObjectType type, uint64_t offset
         assert(ret);
 
         /* Objects may only be located at multiple of 64 bit */
-        if (!VALID64(offset)) {
-                log_debug("Attempt to move to object at non-64bit boundary: %" PRIu64, offset);
-                return -EBADMSG;
-        }
+        if (!VALID64(offset))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to object at non-64bit boundary: %" PRIu64,
+                                       offset);
 
         /* Object may not be located in the file header */
-        if (offset < le64toh(f->header->header_size)) {
-                log_debug("Attempt to move to object located in file header: %" PRIu64, offset);
-                return -EBADMSG;
-        }
+        if (offset < le64toh(f->header->header_size))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to object located in file header: %" PRIu64,
+                                       offset);
 
         r = journal_file_move_to(f, type, false, offset, sizeof(ObjectHeader), &t, &tsize);
         if (r < 0)
@@ -929,29 +906,29 @@ int journal_file_move_to_object(JournalFile *f, ObjectType type, uint64_t offset
         o = (Object*) t;
         s = le64toh(o->object.size);
 
-        if (s == 0) {
-                log_debug("Attempt to move to uninitialized object: %" PRIu64, offset);
-                return -EBADMSG;
-        }
-        if (s < sizeof(ObjectHeader)) {
-                log_debug("Attempt to move to overly short object: %" PRIu64, offset);
-                return -EBADMSG;
-        }
-
-        if (o->object.type <= OBJECT_UNUSED) {
-                log_debug("Attempt to move to object with invalid type: %" PRIu64, offset);
-                return -EBADMSG;
-        }
-
-        if (s < minimum_header_size(o)) {
-                log_debug("Attempt to move to truncated object: %" PRIu64, offset);
-                return -EBADMSG;
-        }
-
-        if (type > OBJECT_UNUSED && o->object.type != type) {
-                log_debug("Attempt to move to object of unexpected type: %" PRIu64, offset);
-                return -EBADMSG;
-        }
+        if (s == 0)
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to uninitialized object: %" PRIu64,
+                                       offset);
+        if (s < sizeof(ObjectHeader))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to overly short object: %" PRIu64,
+                                       offset);
+
+        if (o->object.type <= OBJECT_UNUSED)
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to object with invalid type: %" PRIu64,
+                                       offset);
+
+        if (s < minimum_header_size(o))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to truncated object: %" PRIu64,
+                                       offset);
+
+        if (type > OBJECT_UNUSED && o->object.type != type)
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "Attempt to move to object of unexpected type: %" PRIu64,
+                                       offset);
 
         if (s > tsize) {
                 r = journal_file_move_to(f, type, false, offset, s, &t, NULL);
@@ -1819,7 +1796,9 @@ static int journal_file_append_entry_internal(
         o->entry.realtime = htole64(ts->realtime);
         o->entry.monotonic = htole64(ts->monotonic);
         o->entry.xor_hash = htole64(xor_hash);
-        o->entry.boot_id = boot_id ? *boot_id : f->header->boot_id;
+        if (boot_id)
+                f->header->boot_id = *boot_id;
+        o->entry.boot_id = f->header->boot_id;
 
 #if HAVE_GCRYPT
         r = journal_file_hmac_put_object(f, OBJECT_ENTRY, o, np);
@@ -1952,14 +1931,14 @@ int journal_file_append_entry(
         assert(iovec || n_iovec == 0);
 
         if (ts) {
-                if (!VALID_REALTIME(ts->realtime)) {
-                        log_debug("Invalid realtime timestamp %"PRIu64", refusing entry.", ts->realtime);
-                        return -EBADMSG;
-                }
-                if (!VALID_MONOTONIC(ts->monotonic)) {
-                        log_debug("Invalid monotomic timestamp %"PRIu64", refusing entry.", ts->monotonic);
-                        return -EBADMSG;
-                }
+                if (!VALID_REALTIME(ts->realtime))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid realtime timestamp %" PRIu64 ", refusing entry.",
+                                               ts->realtime);
+                if (!VALID_MONOTONIC(ts->monotonic))
+                        return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                               "Invalid monotomic timestamp %" PRIu64 ", refusing entry.",
+                                               ts->monotonic);
         } else {
                 dual_timestamp_get(&_ts);
                 ts = &_ts;
@@ -2743,10 +2722,10 @@ int journal_file_next_entry(
         }
 
         /* Ensure our array is properly ordered. */
-        if (p > 0 && !check_properly_ordered(ofs, p, direction)) {
-                log_debug("%s: entry array not properly ordered at entry %" PRIu64, f->path, i);
-                return -EBADMSG;
-        }
+        if (p > 0 && !check_properly_ordered(ofs, p, direction))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "%s: entry array not properly ordered at entry %" PRIu64,
+                                       f->path, i);
 
         if (offset)
                 *offset = ofs;
@@ -2819,10 +2798,10 @@ int journal_file_next_entry_for_data(
         }
 
         /* Ensure our array is properly ordered. */
-        if (p > 0 && check_properly_ordered(ofs, p, direction)) {
-                log_debug("%s data entry array not properly ordered at entry %" PRIu64, f->path, i);
-                return -EBADMSG;
-        }
+        if (p > 0 && check_properly_ordered(ofs, p, direction))
+                return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG),
+                                       "%s data entry array not properly ordered at entry %" PRIu64,
+                                       f->path, i);
 
         if (offset)
                 *offset = ofs;
@@ -3206,7 +3185,6 @@ int journal_file_open(
         JournalFile *f;
         void *h;
         int r;
-        char bytes[FORMAT_BYTES_MAX];
 
         assert(ret);
         assert(fd >= 0 || fname);
@@ -3242,9 +3220,23 @@ int journal_file_open(
 #endif
         };
 
-        log_debug("Journal effective settings seal=%s compress=%s compress_threshold_bytes=%s",
-                  yes_no(f->seal), yes_no(JOURNAL_FILE_COMPRESS(f)),
-                  format_bytes(bytes, sizeof(bytes), f->compress_threshold_bytes));
+        if (DEBUG_LOGGING) {
+                static int last_seal = -1, last_compress = -1;
+                static uint64_t last_bytes = UINT64_MAX;
+                char bytes[FORMAT_BYTES_MAX];
+
+                if (last_seal != f->seal ||
+                    last_compress != JOURNAL_FILE_COMPRESS(f) ||
+                    last_bytes != f->compress_threshold_bytes) {
+
+                        log_debug("Journal effective settings seal=%s compress=%s compress_threshold_bytes=%s",
+                                  yes_no(f->seal), yes_no(JOURNAL_FILE_COMPRESS(f)),
+                                  format_bytes(bytes, sizeof bytes, f->compress_threshold_bytes));
+                        last_seal = f->seal;
+                        last_compress = JOURNAL_FILE_COMPRESS(f);
+                        last_bytes = f->compress_threshold_bytes;
+                }
+        }
 
         if (mmap_cache)
                 f->mmap = mmap_cache_ref(mmap_cache);
@@ -3345,6 +3337,13 @@ int journal_file_open(
         }
 
         r = mmap_cache_get(f->mmap, f->cache_fd, f->prot, CONTEXT_HEADER, true, 0, PAGE_ALIGN(sizeof(Header)), &f->last_stat, &h, NULL);
+        if (r == -EINVAL) {
+                /* Some file systems (jffs2 or p9fs) don't support mmap() properly (or only read-only
+                 * mmap()), and return EINVAL in that case. Let's propagate that as a more recognizable error
+                 * code. */
+                r = -EAFNOSUPPORT;
+                goto fail;
+        }
         if (r < 0)
                 goto fail;