X-Git-Url: https://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Fshared%2Flogs-show.c;h=04e1165191068b7494730fa99ebe49d2734200c9;hp=bd7363aa82a2888f6efa183f4423ac3fbe454fb4;hb=affcf189153714f0de4d0986d18e2bc1b35c1b20;hpb=44bc6e1fe0171af19451b5586f7fdd08853ccf5b diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index bd7363aa8..04e116519 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -23,16 +23,23 @@ #include #include #include +#include #include +#include #include "logs-show.h" #include "log.h" #include "util.h" #include "utf8.h" #include "hashmap.h" +#include "fileio.h" #include "journal-internal.h" -#define PRINT_THRESHOLD 128 +/* up to three lines (each up to 100 characters), + or 300 characters, whichever is less */ +#define PRINT_LINE_THRESHOLD 3 +#define PRINT_CHAR_THRESHOLD 300 + #define JSON_THRESHOLD 4096 static int print_catalog(FILE *f, sd_journal *j) { @@ -92,7 +99,7 @@ static bool shall_print(const char *p, size_t l, OutputFlags flags) { if (flags & OUTPUT_SHOW_ALL) return true; - if (l >= PRINT_THRESHOLD) + if (l >= PRINT_CHAR_THRESHOLD) return false; if (!utf8_is_printable(p, l)) @@ -101,10 +108,11 @@ static bool shall_print(const char *p, size_t l, OutputFlags flags) { return true; } -static void 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 continuation = false; + bool ellipsized = false; + int line = 0; if (flags & OUTPUT_COLOR) { if (priority <= LOG_ERR) { @@ -116,31 +124,69 @@ static void print_multiline(FILE *f, unsigned prefix, unsigned n_columns, Output } } - for (pos = message; pos < message + message_len; pos = end + 1) { + /* 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++) { + bool continuation = line > 0; + bool tail_line; int len; for (end = pos; end < message + message_len && *end != '\n'; end++) ; len = end - pos; assert(len >= 0); - if (flags & (OUTPUT_FULL_WIDTH | OUTPUT_SHOW_ALL) || prefix + len + 1 < n_columns) + /* 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 + PRINT_CHAR_THRESHOLD; + + if (flags & (OUTPUT_FULL_WIDTH | OUTPUT_SHOW_ALL) || + (prefix + len + 1 < n_columns && !tail_line)) { fprintf(f, "%*s%s%.*s%s\n", continuation * prefix, "", color_on, len, pos, color_off); - else if (prefix < n_columns && n_columns - prefix >= 3) { - _cleanup_free_ char *e; + continue; + } - e = ellipsize_mem(pos, len, n_columns - prefix, 90); + /* Beyond this point, ellipsization will happen. */ + ellipsized = true; - if (!e) - fprintf(f, "%s%.*s%s\n", color_on, len, pos, color_off); - else - fprintf(f, "%s%s%s\n", color_on, e, color_off); + if (prefix < n_columns && n_columns - prefix >= 3) { + if (n_columns - prefix > (unsigned) len + 3) + fprintf(f, "%*s%s%.*s...%s\n", + continuation * prefix, "", + color_on, len, pos, color_off); + else { + _cleanup_free_ char *e; + + e = ellipsize_mem(pos, len, n_columns - prefix, + tail_line ? 100 : 90); + if (!e) + fprintf(f, "%*s%s%.*s%s\n", + continuation * prefix, "", + color_on, len, pos, color_off); + else + fprintf(f, "%*s%s%s%s\n", + continuation * prefix, "", + color_on, e, color_off); + } } else fputs("...\n", f); - continuation = true; + if (tail_line) + break; } + + return ellipsized; } static int output_short( @@ -157,11 +203,18 @@ static int output_short( _cleanup_free_ char *hostname = NULL, *identifier = NULL, *comm = NULL, *pid = NULL, *fake_pid = NULL, *message = NULL, *realtime = NULL, *monotonic = NULL, *priority = NULL; size_t hostname_len = 0, identifier_len = 0, comm_len = 0, pid_len = 0, fake_pid_len = 0, message_len = 0, realtime_len = 0, monotonic_len = 0, priority_len = 0; int p = LOG_INFO; + bool ellipsized = false; assert(f); assert(j); - sd_journal_set_data_threshold(j, flags & OUTPUT_SHOW_ALL ? 0 : PRINT_THRESHOLD); + /* Set the threshold to one bigger than the actual print + * 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. + */ + sd_journal_set_data_threshold(j, flags & (OUTPUT_SHOW_ALL|OUTPUT_FULL_WIDTH) ? 0 : PRINT_CHAR_THRESHOLD + 1); JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) { @@ -258,8 +311,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); @@ -273,10 +328,21 @@ static int output_short( } 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."); @@ -314,13 +380,14 @@ static int output_short( fprintf(f, ": [%s blob data]\n", format_bytes(bytes, sizeof(bytes), message_len)); } else { fputs(": ", f); - print_multiline(f, n + 2, n_columns, flags, p, message, message_len); + ellipsized |= + print_multiline(f, n + 2, n_columns, flags, p, message, message_len); } if (flags & OUTPUT_CATALOG) print_catalog(f, j); - return 0; + return ellipsized; } static int output_verbose( @@ -334,7 +401,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); @@ -342,11 +409,35 @@ static int output_verbose( sd_journal_set_data_threshold(j, 0); - r = sd_journal_get_realtime_usec(j, &realtime); - if (r < 0) { + 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) { log_full(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, - "Failed to get realtime timestamp: %s", strerror(-r)); + "Failed to get source realtime timestamp: %s", strerror(-r)); return r; + } else { + _cleanup_free_ char *value = NULL; + size_t size; + + r = parse_field(data, length, "_SOURCE_REALTIME_TIMESTAMP=", &value, &size); + if (r < 0) + log_debug("_SOURCE_REALTIME_TIMESTAMP invalid: %s", strerror(-r)); + else { + r = safe_atou64(value, &realtime); + if (r < 0) + log_debug("Failed to parse realtime timestamp: %s", + strerror(-r)); + } + } + + if (r < 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_cursor(j, &cursor); @@ -356,7 +447,9 @@ static int output_verbose( } 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) { @@ -377,7 +470,8 @@ static int output_verbose( } if (flags & OUTPUT_SHOW_ALL || - (((length < PRINT_THRESHOLD) || flags & OUTPUT_FULL_WIDTH) && utf8_is_printable(data, length))) { + (((length < PRINT_CHAR_THRESHOLD) || flags & OUTPUT_FULL_WIDTH) + && utf8_is_printable(data, length))) { fprintf(f, " %s%.*s=", on, fieldlen, (const char*)data); print_multiline(f, 4 + fieldlen + 1, 0, OUTPUT_FULL_WIDTH, 0, c + 1, length - fieldlen - 1); fputs(off, f); @@ -441,12 +535,12 @@ static int output_export( 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) { @@ -454,10 +548,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; @@ -472,8 +568,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); } @@ -582,12 +677,12 @@ static int output_json( 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) @@ -595,16 +690,16 @@ 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; @@ -802,8 +897,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, @@ -817,7 +913,8 @@ int output_journal( sd_journal *j, OutputMode mode, unsigned n_columns, - OutputFlags flags) { + OutputFlags flags, + bool *ellipsized) { int ret; assert(mode >= 0); @@ -828,16 +925,36 @@ int output_journal( ret = output_funcs[mode](f, j, mode, n_columns, flags); fflush(stdout); + + if (ellipsized && ret > 0) + *ellipsized = true; + 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, unsigned n_columns, usec_t not_before, unsigned how_many, - OutputFlags flags) { + OutputFlags flags, + bool *ellipsized) { int r; unsigned line = 0; @@ -887,8 +1004,9 @@ static int show_journal(FILE *f, } line ++; + maybe_print_begin_newline(f, &flags); - r = output_journal(f, j, mode, n_columns, flags); + r = output_journal(f, j, mode, n_columns, flags, ellipsized); if (r < 0) goto finish; } @@ -907,8 +1025,10 @@ static int show_journal(FILE *f, if (r < 0) goto finish; - 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; } @@ -916,7 +1036,7 @@ 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; @@ -959,6 +1079,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; } @@ -974,7 +1104,7 @@ int add_matches_for_user_unit(sd_journal *j, const char *unit, uid_t uid) { 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); + sprintf(muid, "_UID="UID_FMT, uid); (void) ( /* Look for messages from the user service itself */ @@ -998,20 +1128,113 @@ 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); + + k = loop_read(fd, buf, 36, false); + safe_close(fd); + if (k != 36) + _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) { + log_error("Failed to get boot id of container %s: %s", machine, strerror(-r)); + return r; + } + } else { + r = sd_id128_get_boot(&boot_id); + if (r < 0) { + log_error("Failed to get boot id: %s", strerror(-r)); + return r; + } } sd_id128_to_string(boot_id, match + 9); @@ -1037,7 +1260,8 @@ int show_journal_by_unit( unsigned how_many, uid_t uid, OutputFlags flags, - bool system) { + bool system, + bool *ellipsized) { _cleanup_journal_close_ sd_journal*j = NULL; int r; @@ -1054,7 +1278,7 @@ int show_journal_by_unit( if (r < 0) return r; - r = add_match_this_boot(j); + r = add_match_this_boot(j, NULL); if (r < 0) return r; @@ -1072,17 +1296,14 @@ int show_journal_by_unit( log_debug("Journal filter: %s", filter); } - r = show_journal(f, j, mode, n_columns, not_before, how_many, flags); - if (r < 0) - return r; - - return 0; + return show_journal(f, j, mode, n_columns, not_before, how_many, flags, ellipsized); } 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",