[Crash-utility] [PATCH v2] add log -T option to display the message text with human readable timestamp
Dave Anderson
anderson at redhat.com
Tue Apr 21 18:43:30 UTC 2020
----- Original Message -----
> Sometimes, we need to know the accurate time of the log, which
> helps us analyze the problem.
>
> add -T option(like dmesg -T command) for log command to display
> the message text with human readable timestamp.
>
> Signed-off-by: Wang Long <w at laoqinren.net>
Hi Wang,
This is a nice feature. Note that I did add a stanza for backwards-compatibility
with Linux 3.4 and earlier kernels that didn't have variable length records:
@@ -4962,6 +4974,8 @@ dump_log(int msg_flags)
return;
}
+ if (msg_flags & SHOW_LOG_CTIME)
+ option_not_supported('T');
if (msg_flags & SHOW_LOG_DICT)
option_not_supported('d');
if ((msg_flags & SHOW_LOG_TEXT) && STREQ(pc->curcmd, "log"))
Queued for crash-7.2.9:
https://github.com/crash-utility/crash/commit/c86250bce29f17610647772f838e1bb9d622ea8c
Thanks,
Dave
> ---
> defs.h | 2 ++
> help.c | 28 +++++++++++++++++++++++++++-
> kernel.c | 23 +++++++++++++++++++++--
> 3 files changed, 50 insertions(+), 3 deletions(-)
>
> diff --git a/defs.h b/defs.h
> index d8eda5e..4e57a56 100644
> --- a/defs.h
> +++ b/defs.h
> @@ -763,6 +763,7 @@ struct kernel_table { /* kernel data */
> } vmcoreinfo;
> ulonglong flags2;
> char *source_tree;
> + struct timespec boot_date;
> };
>
> /*
> @@ -5577,6 +5578,7 @@ void dump_log(int);
> #define SHOW_LOG_DICT (0x2)
> #define SHOW_LOG_TEXT (0x4)
> #define SHOW_LOG_AUDIT (0x8)
> +#define SHOW_LOG_CTIME (0x10)
> void set_cpu(int);
> void clear_machdep_cache(void);
> struct stack_hook *gather_text_list(struct bt_info *);
> diff --git a/help.c b/help.c
> index c443cad..1ee70f7 100644
> --- a/help.c
> +++ b/help.c
> @@ -3892,12 +3892,13 @@ NULL
> char *help_log[] = {
> "log",
> "dump system message buffer",
> -"[-tdma]",
> +"[-Ttdma]",
> " This command dumps the kernel log_buf contents in chronological order.
> The",
> " command supports the older log_buf formats, which may or may not contain
> a",
> " timestamp inserted prior to each message, as well as the newer
> variable-length",
> " record format, where the timestamp is contained in each log entry's
> header.",
> " ",
> +" -T Display the message text with human readable timestamp.",
> " -t Display the message text without the timestamp; only applicable to
> the",
> " variable-length record format.",
> " -d Display the dictionary of key/value pair properties that are
> optionally",
> @@ -4031,6 +4032,31 @@ char *help_log[] = {
> " type=1307 audit(1489384479.809:4346): cwd=\"/proc\"",
> " ...",
> " ",
> +" Display the message text with human readable timestamp.\n"
> +" %s> log -T",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x0000000000000000-0x000000000009fbff] usable",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x000000000009fc00-0x000000000009ffff] reserved",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x00000000000f0000-0x00000000000fffff] reserved",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x0000000000100000-0x00000000dffeffff] usable",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x00000000dfff0000-0x00000000dfffffff] ACPI data",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x00000000fec00000-0x00000000fec00fff] reserved",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x00000000fee00000-0x00000000fee00fff] reserved",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x00000000fffc0000-0x00000000ffffffff] reserved",
> +" [Sat Apr 4 07:41:09 2020] BIOS-e820: [mem
> 0x0000000100000000-0x000000011fffffff] usable",
> +" [Sat Apr 4 07:41:09 2020] NX (Execute Disable) protection: active",
> +" [Sat Apr 4 07:41:09 2020] SMBIOS 2.5 present.",
> +" [Sat Apr 4 07:41:09 2020] DMI: innotek GmbH VirtualBox/VirtualBox,
> BIOS VirtualBox 12/01/2006",
> +" [Sat Apr 4 07:41:09 2020] Hypervisor detected: KVM",
> +" [Sat Apr 4 07:41:09 2020] kvm-clock: Using msrs 4b564d01 and
> 4b564d00",
> +" [Sat Apr 4 07:41:09 2020] kvm-clock: cpu 0, msr 6de01001, primary cpu
> clock",
> +" [Sat Apr 4 07:41:09 2020] kvm-clock: using sched offset of 11838753697
> cycles",
> +" [Sat Apr 4 07:41:09 2020] clocksource: kvm-clock: mask:
> 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns",
> +" [Sat Apr 4 07:41:09 2020] e820: update [mem 0x00000000-0x00000fff]
> usable ==> reserved",
> +" [Sat Apr 4 07:41:09 2020] e820: remove [mem 0x000a0000-0x000fffff]
> usable",
> +" [Sat Apr 4 07:41:09 2020] last_pfn = 0x120000 max_arch_pfn =
> 0x400000000",
> +" [Sat Apr 4 07:41:09 2020] MTRR default type: uncachable",
> +" [Sat Apr 4 07:41:09 2020] MTRR variable ranges disabled:",
> +" ...",
> NULL
> };
>
> diff --git a/kernel.c b/kernel.c
> index 7604fac..7e68e6d 100644
> --- a/kernel.c
> +++ b/kernel.c
> @@ -4912,9 +4912,12 @@ cmd_log(void)
>
> msg_flags = 0;
>
> - while ((c = getopt(argcnt, args, "tdma")) != EOF) {
> + while ((c = getopt(argcnt, args, "Ttdma")) != EOF) {
> switch(c)
> {
> + case 'T':
> + msg_flags |= SHOW_LOG_CTIME;
> + break;
> case 't':
> msg_flags |= SHOW_LOG_TEXT;
> break;
> @@ -4936,6 +4939,15 @@ cmd_log(void)
> if (argerrs)
> cmd_usage(pc->curcmd, SYNOPSIS);
>
> + if (kt->boot_date.tv_sec == 0) {
> + ulonglong uptime_jiffies;
> + ulong uptime_sec;
> + get_uptime(NULL, &uptime_jiffies);
> + uptime_sec = (uptime_jiffies)/(ulonglong)machdep->hz;
> + kt->boot_date.tv_sec = kt->date.tv_sec - uptime_sec;
> + kt->boot_date.tv_nsec = 0;
> + }
> +
> if (msg_flags & SHOW_LOG_AUDIT) {
> dump_audit();
> return;
> @@ -5154,7 +5166,12 @@ dump_log_entry(char *logptr, int msg_flags)
> if ((msg_flags & SHOW_LOG_TEXT) == 0) {
> nanos = (ulonglong)ts_nsec / (ulonglong)1000000000;
> rem = (ulonglong)ts_nsec % (ulonglong)1000000000;
> - sprintf(buf, "[%5lld.%06ld] ", nanos, rem/1000);
> + if (msg_flags & SHOW_LOG_CTIME) {
> + time_t t = kt->boot_date.tv_sec + nanos;
> + sprintf(buf, "[%s] ", strip_linefeeds(ctime(&t)));
> + }
> + else
> + sprintf(buf, "[%5lld.%06ld] ", nanos, rem/1000);
> ilen = strlen(buf);
> fprintf(fp, "%s", buf);
> }
> @@ -6018,6 +6035,8 @@ dump_kernel_table(int verbose)
> get_xtime(&kt->date);
> fprintf(fp, " date: %s\n",
> strip_linefeeds(ctime(&kt->date.tv_sec)));
> + fprintf(fp, " boot_ date: %s\n",
> + strip_linefeeds(ctime(&kt->boot_date.tv_sec)));
> fprintf(fp, " proc_version: %s\n",
> strip_linefeeds(kt->proc_version));
> fprintf(fp, " new_utsname: \n");
> fprintf(fp, " .sysname: %s\n", uts->sysname);
> --
> 1.8.3.1
>
>
>
>
More information about the Crash-utility
mailing list