X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Fshared%2Flogs-show.c;h=ac5eb16f62dab9c8c8ca24f30919611536034058;hp=af738a313e01613802fca058ee761b1386c12c46;hb=7aa263bce73215d1d839aa87f5bad388829cbb8a;hpb=a6f0104a16350a4c2660837da6e0e5c2e50e2389 diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index af738a313..ac5eb16f6 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -20,10 +20,10 @@ ***/ #include -#include #include -#include +#include #include +#include #include "logs-show.h" #include "log.h" @@ -31,6 +31,9 @@ #include "utf8.h" #include "hashmap.h" #include "journal-internal.h" +#include "formats-util.h" +#include "process-util.h" +#include "terminal-util.h" /* up to three lines (each up to 100 characters), or 300 characters, whichever is less */ @@ -105,7 +108,7 @@ static bool shall_print(const char *p, size_t l, OutputFlags flags) { return true; } -static bool print_multiline(FILE *f, unsigned prefix, unsigned n_columns, OutputMode flags, int priority, const char* message, size_t message_len) { +static bool print_multiline(FILE *f, unsigned prefix, unsigned n_columns, OutputFlags flags, int priority, const char* message, size_t message_len) { const char *color_on = "", *color_off = ""; const char *pos, *end; bool ellipsized = false; @@ -121,6 +124,11 @@ static bool print_multiline(FILE *f, unsigned prefix, unsigned n_columns, Output } } + /* A special case: make sure that we print a newline when + the message is empty. */ + if (message_len == 0) + fputs("\n", f); + for (pos = message; pos < message + message_len; pos = end + 1, line++) { @@ -132,14 +140,14 @@ static bool print_multiline(FILE *f, unsigned prefix, unsigned n_columns, Output len = end - pos; assert(len >= 0); - /* We need to figure out when we are showing the last line, and + /* We need to figure out when we are showing not-last line, *and* * will skip subsequent lines. In that case, we will put the dots * at the end of the line, instead of putting dots in the middle * or not at all. */ tail_line = line + 1 == PRINT_LINE_THRESHOLD || - end + 1 >= message + message_len; + end + 1 >= message + PRINT_CHAR_THRESHOLD; if (flags & (OUTPUT_FULL_WIDTH | OUTPUT_SHOW_ALL) || (prefix + len + 1 < n_columns && !tail_line)) { @@ -201,7 +209,7 @@ static int output_short( assert(j); /* Set the threshold to one bigger than the actual print - * treshold, so that if the line is actually longer than what + * threshold, so that if the line is actually longer than what * we're willing to print, ellipsization will occur. This way * we won't output a misleading line without any indication of * truncation. @@ -264,7 +272,7 @@ static int output_short( } if (r < 0) - return r; + return log_error_errno(r, "Failed to get journal fields: %m"); if (!message) return 0; @@ -287,10 +295,8 @@ static int output_short( if (r < 0) r = sd_journal_get_monotonic_usec(j, &t, &boot_id); - if (r < 0) { - log_error("Failed to get monotonic timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get monotonic timestamp: %m"); fprintf(f, "[%5llu.%06llu]", (unsigned long long) (t / USEC_PER_SEC), @@ -303,8 +309,10 @@ static int output_short( uint64_t x; time_t t; struct tm tm; + struct tm *(*gettime_r)(const time_t *, struct tm *); r = -ENOENT; + gettime_r = (flags & OUTPUT_UTC) ? gmtime_r : localtime_r; if (realtime) r = safe_atou64(realtime, &x); @@ -312,16 +320,25 @@ static int output_short( if (r < 0) r = sd_journal_get_realtime_usec(j, &x); - if (r < 0) { - log_error("Failed to get realtime timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get realtime timestamp: %m"); t = (time_t) (x / USEC_PER_SEC); - if (mode == OUTPUT_SHORT_ISO) - r = strftime(buf, sizeof(buf), "%Y-%m-%dT%H:%M:%S%z", localtime_r(&t, &tm)); - else - r = strftime(buf, sizeof(buf), "%b %d %H:%M:%S", localtime_r(&t, &tm)); + + switch(mode) { + case OUTPUT_SHORT_ISO: + r = strftime(buf, sizeof(buf), "%Y-%m-%dT%H:%M:%S%z", gettime_r(&t, &tm)); + break; + case OUTPUT_SHORT_PRECISE: + r = strftime(buf, sizeof(buf), "%b %d %H:%M:%S", gettime_r(&t, &tm)); + if (r > 0) { + snprintf(buf + strlen(buf), sizeof(buf) - strlen(buf), + ".%06llu", (unsigned long long) (x % USEC_PER_SEC)); + } + break; + default: + r = strftime(buf, sizeof(buf), "%b %d %H:%M:%S", gettime_r(&t, &tm)); + } if (r <= 0) { log_error("Failed to format time."); @@ -344,7 +361,7 @@ static int output_short( fprintf(f, " %.*s", (int) comm_len, comm); n += comm_len + 1; } else - fputc(' ', f); + fputs(" unknown", f); if (pid && shall_print(pid, pid_len, flags)) { fprintf(f, "[%.*s]", (int) pid_len, pid); @@ -380,7 +397,7 @@ static int output_verbose( size_t length; _cleanup_free_ char *cursor = NULL; uint64_t realtime; - char ts[FORMAT_TIMESTAMP_MAX]; + char ts[FORMAT_TIMESTAMP_MAX + 7]; int r; assert(f); @@ -388,21 +405,39 @@ static int output_verbose( sd_journal_set_data_threshold(j, 0); - r = sd_journal_get_realtime_usec(j, &realtime); - if (r < 0) { - log_full(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, - "Failed to get realtime timestamp: %s", strerror(-r)); - return r; + r = sd_journal_get_data(j, "_SOURCE_REALTIME_TIMESTAMP", &data, &length); + if (r == -ENOENT) + log_debug("Source realtime timestamp not found"); + else if (r < 0) + return log_full_errno(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, r, "Failed to get source realtime timestamp: %m"); + else { + _cleanup_free_ char *value = NULL; + size_t size; + + r = parse_field(data, length, "_SOURCE_REALTIME_TIMESTAMP=", &value, &size); + if (r < 0) + log_debug_errno(r, "_SOURCE_REALTIME_TIMESTAMP invalid: %m"); + else { + r = safe_atou64(value, &realtime); + if (r < 0) + log_debug_errno(r, "Failed to parse realtime timestamp: %m"); + } } - r = sd_journal_get_cursor(j, &cursor); if (r < 0) { - log_error("Failed to get cursor: %s", strerror(-r)); - return r; + r = sd_journal_get_realtime_usec(j, &realtime); + if (r < 0) + return log_full_errno(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, r, "Failed to get realtime timestamp: %m"); } + r = sd_journal_get_cursor(j, &cursor); + if (r < 0) + return log_error_errno(r, "Failed to get cursor: %m"); + fprintf(f, "%s [%s]\n", - format_timestamp(ts, sizeof(ts), realtime), + flags & OUTPUT_UTC ? + format_timestamp_us_utc(ts, sizeof(ts), realtime) : + format_timestamp_us(ts, sizeof(ts), realtime), cursor); JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) { @@ -469,31 +504,25 @@ static int output_export( sd_journal_set_data_threshold(j, 0); r = sd_journal_get_realtime_usec(j, &realtime); - if (r < 0) { - log_error("Failed to get realtime timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get realtime timestamp: %m"); r = sd_journal_get_monotonic_usec(j, &monotonic, &boot_id); - if (r < 0) { - log_error("Failed to get monotonic timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get monotonic timestamp: %m"); r = sd_journal_get_cursor(j, &cursor); - if (r < 0) { - log_error("Failed to get cursor: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get cursor: %m"); fprintf(f, "__CURSOR=%s\n" - "__REALTIME_TIMESTAMP=%llu\n" - "__MONOTONIC_TIMESTAMP=%llu\n" + "__REALTIME_TIMESTAMP="USEC_FMT"\n" + "__MONOTONIC_TIMESTAMP="USEC_FMT"\n" "_BOOT_ID=%s\n", cursor, - (unsigned long long) realtime, - (unsigned long long) monotonic, + realtime, + monotonic, sd_id128_to_string(boot_id, sid)); JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) { @@ -501,10 +530,12 @@ static int output_export( /* We already printed the boot id, from the data in * the header, hence let's suppress it here */ if (length >= 9 && - hasprefix(data, "_BOOT_ID=")) + startswith(data, "_BOOT_ID=")) continue; - if (!utf8_is_printable(data, length)) { + if (utf8_is_printable_newline(data, length, false)) + fwrite(data, length, 1, f); + else { const char *c; uint64_t le64; @@ -519,8 +550,7 @@ static int output_export( le64 = htole64(length - (c - (const char*) data) - 1); fwrite(&le64, sizeof(le64), 1, f); fwrite(c + 1, length - (c - (const char*) data) - 1, 1, f); - } else - fwrite(data, length, 1, f); + } fputc('\n', f); } @@ -608,33 +638,27 @@ static int output_json( sd_journal_set_data_threshold(j, flags & OUTPUT_SHOW_ALL ? 0 : JSON_THRESHOLD); r = sd_journal_get_realtime_usec(j, &realtime); - if (r < 0) { - log_error("Failed to get realtime timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get realtime timestamp: %m"); r = sd_journal_get_monotonic_usec(j, &monotonic, &boot_id); - if (r < 0) { - log_error("Failed to get monotonic timestamp: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get monotonic timestamp: %m"); r = sd_journal_get_cursor(j, &cursor); - if (r < 0) { - log_error("Failed to get cursor: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to get cursor: %m"); if (mode == OUTPUT_JSON_PRETTY) fprintf(f, "{\n" "\t\"__CURSOR\" : \"%s\",\n" - "\t\"__REALTIME_TIMESTAMP\" : \"%llu\",\n" - "\t\"__MONOTONIC_TIMESTAMP\" : \"%llu\",\n" + "\t\"__REALTIME_TIMESTAMP\" : \""USEC_FMT"\",\n" + "\t\"__MONOTONIC_TIMESTAMP\" : \""USEC_FMT"\",\n" "\t\"_BOOT_ID\" : \"%s\"", cursor, - (unsigned long long) realtime, - (unsigned long long) monotonic, + realtime, + monotonic, sd_id128_to_string(boot_id, sid)); else { if (mode == OUTPUT_JSON_SSE) @@ -642,18 +666,18 @@ static int output_json( fprintf(f, "{ \"__CURSOR\" : \"%s\", " - "\"__REALTIME_TIMESTAMP\" : \"%llu\", " - "\"__MONOTONIC_TIMESTAMP\" : \"%llu\", " + "\"__REALTIME_TIMESTAMP\" : \""USEC_FMT"\", " + "\"__MONOTONIC_TIMESTAMP\" : \""USEC_FMT"\", " "\"_BOOT_ID\" : \"%s\"", cursor, - (unsigned long long) realtime, - (unsigned long long) monotonic, + realtime, + monotonic, sd_id128_to_string(boot_id, sid)); } - h = hashmap_new(string_hash_func, string_compare_func); + h = hashmap_new(&string_hash_ops); if (!h) - return -ENOMEM; + return log_oom(); /* First round, iterate through the entry and count how often each field appears */ JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) { @@ -671,7 +695,7 @@ static int output_json( n = strndup(data, eq - (const char*) data); if (!n) { - r = -ENOMEM; + r = log_oom(); goto finish; } @@ -680,13 +704,16 @@ static int output_json( r = hashmap_put(h, n, UINT_TO_PTR(1)); if (r < 0) { free(n); + log_oom(); goto finish; } } else { r = hashmap_update(h, n, UINT_TO_PTR(u + 1)); free(n); - if (r < 0) + if (r < 0) { + log_oom(); goto finish; + } } } @@ -724,7 +751,7 @@ static int output_json( n = strndup(data, m); if (!n) { - r = -ENOMEM; + r = log_oom(); goto finish; } @@ -829,8 +856,7 @@ static int output_cat( if (r == -ENOENT) return 0; - log_error("Failed to get data: %s", strerror(-r)); - return r; + return log_error_errno(r, "Failed to get data: %m"); } assert(l >= 8); @@ -849,8 +875,9 @@ static int (*output_funcs[_OUTPUT_MODE_MAX])( OutputFlags flags) = { [OUTPUT_SHORT] = output_short, - [OUTPUT_SHORT_MONOTONIC] = output_short, [OUTPUT_SHORT_ISO] = output_short, + [OUTPUT_SHORT_PRECISE] = output_short, + [OUTPUT_SHORT_MONOTONIC] = output_short, [OUTPUT_VERBOSE] = output_verbose, [OUTPUT_EXPORT] = output_export, [OUTPUT_JSON] = output_json, @@ -883,6 +910,21 @@ int output_journal( return ret; } +static int maybe_print_begin_newline(FILE *f, OutputFlags *flags) { + assert(f); + assert(flags); + + if (!(*flags & OUTPUT_BEGIN_NEWLINE)) + return 0; + + /* Print a beginning new line if that's request, but only once + * on the first line we print. */ + + fputc('\n', f); + *flags &= ~OUTPUT_BEGIN_NEWLINE; + return 0; +} + static int show_journal(FILE *f, sd_journal *j, OutputMode mode, @@ -904,11 +946,11 @@ static int show_journal(FILE *f, /* Seek to end */ r = sd_journal_seek_tail(j); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to seek to tail: %m"); r = sd_journal_previous_skip(j, how_many); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to skip previous: %m"); for (;;) { for (;;) { @@ -917,7 +959,7 @@ static int show_journal(FILE *f, if (need_seek) { r = sd_journal_next(j); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to iterate through journal: %m"); } if (r == 0) @@ -933,35 +975,38 @@ static int show_journal(FILE *f, if (r == -ESTALE) continue; else if (r < 0) - goto finish; + return log_error_errno(r, "Failed to get journal time: %m"); if (usec < not_before) continue; } line ++; + maybe_print_begin_newline(f, &flags); r = output_journal(f, j, mode, n_columns, flags, ellipsized); if (r < 0) - goto finish; + return r; } if (warn_cutoff && line < how_many && not_before > 0) { sd_id128_t boot_id; - usec_t cutoff; + usec_t cutoff = 0; /* Check whether the cutoff line is too early */ r = sd_id128_get_boot(&boot_id); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to get boot id: %m"); r = sd_journal_get_cutoff_monotonic_usec(j, boot_id, &cutoff, NULL); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to get journal cutoff time: %m"); - if (r > 0 && not_before < cutoff) + if (r > 0 && not_before < cutoff) { + maybe_print_begin_newline(f, &flags); fprintf(f, "Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.\n"); + } warn_cutoff = false; } @@ -969,14 +1014,13 @@ static int show_journal(FILE *f, if (!(flags & OUTPUT_FOLLOW)) break; - r = sd_journal_wait(j, (usec_t) -1); + r = sd_journal_wait(j, USEC_INFINITY); if (r < 0) - goto finish; + return log_error_errno(r, "Failed to wait for journal: %m"); } -finish: - return r; + return 0; } int add_matches_for_unit(sd_journal *j, const char *unit) { @@ -986,10 +1030,10 @@ int add_matches_for_unit(sd_journal *j, const char *unit) { assert(j); assert(unit); - m1 = strappenda("_SYSTEMD_UNIT=", unit); - m2 = strappenda("COREDUMP_UNIT=", unit); - m3 = strappenda("UNIT=", unit); - m4 = strappenda("OBJECT_SYSTEMD_UNIT=", unit); + m1 = strjoina("_SYSTEMD_UNIT=", unit); + m2 = strjoina("COREDUMP_UNIT=", unit); + m3 = strjoina("UNIT=", unit); + m4 = strjoina("OBJECT_SYSTEMD_UNIT=", unit); (void)( /* Look for messages from the service itself */ @@ -1012,6 +1056,16 @@ int add_matches_for_unit(sd_journal *j, const char *unit) { (r = sd_journal_add_match(j, m4, 0)) ); + if (r == 0 && endswith(unit, ".slice")) { + char *m5 = strappend("_SYSTEMD_SLICE=", unit); + + /* Show all messages belonging to a slice */ + (void)( + (r = sd_journal_add_disjunction(j)) || + (r = sd_journal_add_match(j, m5, 0)) + ); + } + return r; } @@ -1023,11 +1077,11 @@ int add_matches_for_user_unit(sd_journal *j, const char *unit, uid_t uid) { assert(j); assert(unit); - m1 = strappenda("_SYSTEMD_USER_UNIT=", unit); - m2 = strappenda("USER_UNIT=", unit); - m3 = strappenda("COREDUMP_USER_UNIT=", unit); - m4 = strappenda("OBJECT_SYSTEMD_USER_UNIT=", unit); - sprintf(muid, "_UID=%lu", (unsigned long) uid); + m1 = strjoina("_SYSTEMD_USER_UNIT=", unit); + m2 = strjoina("USER_UNIT=", unit); + m3 = strjoina("COREDUMP_USER_UNIT=", unit); + m4 = strjoina("OBJECT_SYSTEMD_USER_UNIT=", unit); + sprintf(muid, "_UID="UID_FMT, uid); (void) ( /* Look for messages from the user service itself */ @@ -1051,32 +1105,119 @@ int add_matches_for_user_unit(sd_journal *j, const char *unit, uid_t uid) { (r = sd_journal_add_match(j, muid, 0)) || (r = sd_journal_add_match(j, "_UID=0", 0)) ); + + if (r == 0 && endswith(unit, ".slice")) { + char *m5 = strappend("_SYSTEMD_SLICE=", unit); + + /* Show all messages belonging to a slice */ + (void)( + (r = sd_journal_add_disjunction(j)) || + (r = sd_journal_add_match(j, m5, 0)) || + (r = sd_journal_add_match(j, muid, 0)) + ); + } + return r; } -int add_match_this_boot(sd_journal *j) { +static int get_boot_id_for_machine(const char *machine, sd_id128_t *boot_id) { + _cleanup_close_pair_ int pair[2] = { -1, -1 }; + _cleanup_close_ int pidnsfd = -1, mntnsfd = -1, rootfd = -1; + pid_t pid, child; + siginfo_t si; + char buf[37]; + ssize_t k; + int r; + + assert(machine); + assert(boot_id); + + if (!machine_name_is_valid(machine)) + return -EINVAL; + + r = container_get_leader(machine, &pid); + if (r < 0) + return r; + + r = namespace_open(pid, &pidnsfd, &mntnsfd, NULL, &rootfd); + if (r < 0) + return r; + + if (socketpair(AF_UNIX, SOCK_DGRAM, 0, pair) < 0) + return -errno; + + child = fork(); + if (child < 0) + return -errno; + + if (child == 0) { + int fd; + + pair[0] = safe_close(pair[0]); + + r = namespace_enter(pidnsfd, mntnsfd, -1, rootfd); + if (r < 0) + _exit(EXIT_FAILURE); + + fd = open("/proc/sys/kernel/random/boot_id", O_RDONLY|O_CLOEXEC|O_NOCTTY); + if (fd < 0) + _exit(EXIT_FAILURE); + + r = loop_read_exact(fd, buf, 36, false); + safe_close(fd); + if (r < 0) + _exit(EXIT_FAILURE); + + k = send(pair[1], buf, 36, MSG_NOSIGNAL); + if (k != 36) + _exit(EXIT_FAILURE); + + _exit(EXIT_SUCCESS); + } + + pair[1] = safe_close(pair[1]); + + r = wait_for_terminate(child, &si); + if (r < 0 || si.si_code != CLD_EXITED || si.si_status != EXIT_SUCCESS) + return r < 0 ? r : -EIO; + + k = recv(pair[0], buf, 36, 0); + if (k != 36) + return -EIO; + + buf[36] = 0; + r = sd_id128_from_string(buf, boot_id); + if (r < 0) + return r; + + return 0; +} + +int add_match_this_boot(sd_journal *j, const char *machine) { char match[9+32+1] = "_BOOT_ID="; sd_id128_t boot_id; int r; assert(j); - r = sd_id128_get_boot(&boot_id); - if (r < 0) { - log_error("Failed to get boot id: %s", strerror(-r)); - return r; + if (machine) { + r = get_boot_id_for_machine(machine, &boot_id); + if (r < 0) + return log_error_errno(r, "Failed to get boot id of container %s: %m", machine); + } else { + r = sd_id128_get_boot(&boot_id); + if (r < 0) + return log_error_errno(r, "Failed to get boot id: %m"); } sd_id128_to_string(boot_id, match + 9); r = sd_journal_add_match(j, match, strlen(match)); - if (r < 0) { - log_error("Failed to add match: %s", strerror(-r)); - return r; - } + if (r < 0) + return log_error_errno(r, "Failed to add match: %m"); r = sd_journal_add_conjunction(j); if (r < 0) - return r; + return log_error_errno(r, "Failed to add conjunction: %m"); return 0; } @@ -1090,12 +1231,12 @@ int show_journal_by_unit( unsigned how_many, uid_t uid, OutputFlags flags, - bool system, + int journal_open_flags, + bool system_unit, bool *ellipsized) { _cleanup_journal_close_ sd_journal*j = NULL; int r; - int jflags = SD_JOURNAL_LOCAL_ONLY | system * SD_JOURNAL_SYSTEM; assert(mode >= 0); assert(mode < _OUTPUT_MODE_MAX); @@ -1104,25 +1245,28 @@ int show_journal_by_unit( if (how_many <= 0) return 0; - r = sd_journal_open(&j, jflags); + r = sd_journal_open(&j, journal_open_flags); if (r < 0) - return r; + return log_error_errno(r, "Failed to open journal: %m"); - r = add_match_this_boot(j); + r = add_match_this_boot(j, NULL); if (r < 0) return r; - if (system) + if (system_unit) r = add_matches_for_unit(j, unit); else r = add_matches_for_user_unit(j, unit, uid); if (r < 0) - return r; + return log_error_errno(r, "Failed to add unit matches: %m"); - if (_unlikely_(log_get_max_level() >= LOG_PRI(LOG_DEBUG))) { + if (_unlikely_(log_get_max_level() >= LOG_DEBUG)) { _cleanup_free_ char *filter; filter = journal_make_match_string(j); + if (!filter) + return log_oom(); + log_debug("Journal filter: %s", filter); } @@ -1131,8 +1275,9 @@ int show_journal_by_unit( static const char *const output_mode_table[_OUTPUT_MODE_MAX] = { [OUTPUT_SHORT] = "short", - [OUTPUT_SHORT_MONOTONIC] = "short-monotonic", [OUTPUT_SHORT_ISO] = "short-iso", + [OUTPUT_SHORT_PRECISE] = "short-precise", + [OUTPUT_SHORT_MONOTONIC] = "short-monotonic", [OUTPUT_VERBOSE] = "verbose", [OUTPUT_EXPORT] = "export", [OUTPUT_JSON] = "json",