Re: [Crash-utility] Crash-utility Digest, Vol 175, Issue 28

On Apr 19, 2020, at 7:11 PM, crash-utility-request(a)redhat.com wrote: Send Crash-utility mailing list submissions to crash-utility(a)redhat.com To subscribe or unsubscribe via the World Wide Web, visit https://www.redhat.com/mailman/listinfo/crash-utility or, via email, send a message with subject or body 'help' to crash-utility-request(a)redhat.com You can reach the person managing the list at crash-utility-owner(a)redhat.com When replying, please edit your Subject line so it is more specific than "Re: Contents of Crash-utility digest..." Today's Topics: 1. Re: Crash-utility Digest, Vol 175, Issue 27 (Jon Deacon) ---------------------------------------------------------------------- Message: 1 Date: Sun, 19 Apr 2020 19:10:49 -0400 From: Jon Deacon <jdeacon60(a)gmail.com&gt; To: crash-utility(a)redhat.com Subject: Re: [Crash-utility] Crash-utility Digest, Vol 175, Issue 27 Message-ID: <BBA9A8B9-A0EA-404C-AC73-7814A9544219(a)gmail.com&gt; Content-Type: text/plain; charset=utf-8 Would you please take me off your list totally ridiculous Sent from my iPhone > On Apr 19, 2020, at 4:01 PM, crash-utility-request(a)redhat.com wrote: > > ?Send Crash-utility mailing list submissions to > crash-utility(a)redhat.com > > To subscribe or unsubscribe via the World Wide Web, visit > https://www.redhat.com/mailman/listinfo/crash-utility > or, via email, send a message with subject or body 'help' to > crash-utility-request(a)redhat.com > > You can reach the person managing the list at > crash-utility-owner(a)redhat.com > > When replying, please edit your Subject line so it is more specific > than "Re: Contents of Crash-utility digest..." > > > Today's Topics: > > 1. Re: [PATCH] add log -T option to display the message text > with human readable timestamp (Dave Anderson) > 2. Re: [PATCH] add log -T option to display the message text > with human readable timestamp (Dave Anderson) > 3. Re: [PATCH] add log -T option to display the message text > with human readable timestamp (Moore, Martin (Linux ERT)) > > > ---------------------------------------------------------------------- > > Message: 1 > Date: Sun, 19 Apr 2020 15:34:46 -0400 (EDT) > From: Dave Anderson <anderson(a)redhat.com&gt; > To: Wang Long <w(a)laoqinren.net&gt; > Cc: crash-utility(a)redhat.com > Subject: Re: [Crash-utility] [PATCH] add log -T option to display the > message text with human readable timestamp > Message-ID: > <116726603.23908736.1587324886732.JavaMail.zimbra(a)redhat.com&gt; > Content-Type: text/plain; charset=utf-8 > > > > ----- 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(a)laoqinren.net&gt; > > Did you attempt this patch on a live system? Because your patch to > kernel_init() hangs the session. I didn't bother to investigate beyond > adding these two debug statements around your addition to kernel_init(): > > error(INFO, "start patch...\n"); > 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; > error(INFO, "end patch...\n"); > > And that's where it hangs: > > $ ./crash > > crash 7.2.9rc13 > Copyright (C) 2002-2020 Red Hat, Inc. > Copyright (C) 2004, 2005, 2006, 2010 IBM Corporation > Copyright (C) 1999-2006 Hewlett-Packard Co > Copyright (C) 2005, 2006, 2011, 2012 Fujitsu Limited > Copyright (C) 2006, 2007 VA Linux Systems Japan K.K. > Copyright (C) 2005, 2011 NEC Corporation > Copyright (C) 1999, 2002, 2007 Silicon Graphics, Inc. > Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc. > This program is free software, covered by the GNU General Public License, > and you are welcome to change it and/or distribute copies of it under > certain conditions. Enter "help copying" to see the conditions. > This program has absolutely no warranty. Enter "help warranty" for details. > > GNU gdb (GDB) 7.6 > Copyright (C) 2013 Free Software Foundation, Inc. > License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> > This is free software: you are free to change and redistribute it. > There is NO WARRANTY, to the extent permitted by law. Type "show copying" > and "show warranty" for details. > This GDB was configured as "x86_64-unknown-linux-gnu"... > > WARNING: kernel relocated [796MB]: patching 85687 gdb minimal_symbol values > > crash: start patch... > > <hang> > > And it shows a cpu spinning at 100%: > > $ top > top - 15:26:43 up 38 days, 3:41, 5 users, load average: 1.00, 0.89, 0.65 > Tasks: 280 total, 2 running, 278 sleeping, 0 stopped, 0 zombie > %Cpu(s): 3.9 us, 8.7 sy, 0.0 ni, 87.3 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st > KiB Mem : 15907600 total, 455876 free, 1232832 used, 14218892 buff/cache > KiB Swap: 8060924 total, 7395580 free, 665344 used. 14176220 avail Mem > PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND > 26668 root 20 0 350268 213688 5680 R 100.0 1.3 5:42.70 crash > 1707 root 20 0 115692 1184 688 S 0.3 0.0 2:16.52 ksmtuned > 12852 anderson 20 0 4235240 274608 20320 S 0.3 1.7 601:46.85 gnome-shell > 13060 anderson 20 0 804924 14100 3744 S 0.3 0.1 118:44.59 gsd-color > 27045 anderson 20 0 172452 2532 1648 R 0.3 0.0 0:00.08 top > 1 root 20 0 210504 5592 3224 S 0.0 0.0 18:14.19 systemd > ... > > I'll let you figure it out... > > Dave > > > > > > >> --- >> defs.h | 2 ++ >> help.c | 28 +++++++++++++++++++++++++++- >> kernel.c | 22 ++++++++++++++++++++-- >> 3 files changed, 49 insertions(+), 3 deletions(-) >> >> diff --git a/defs.h b/defs.h >> index d8eda5e..1644dbd 100644 >> --- a/defs.h/ >> +++ b/defs.h >> @@ -689,6 +689,7 @@ struct kernel_table { /* kernel data */ >> ulong kernel_module; >> int mods_installed; >> struct timespec date; >> + struct timespec boot_date; >> char proc_version[BUFSIZE]; >> struct new_utsname utsname; >> uint kernel_version[3]; >> @@ -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..016d8d9 100644 >> --- a/kernel.c >> +++ b/kernel.c >> @@ -111,6 +111,8 @@ kernel_init() >> char *irq_desc_type_name; >> ulong pv_init_ops;/ >> struct gnu_request req; >> + ulonglong uptime_jiffies; >> + ulong uptime_sec; >> >> if (pc->flags & KERNEL_DEBUG_QUERY) >> return; >> @@ -294,6 +296,14 @@ kernel_init() >> } else >> error(INFO, "cannot determine base kernel version\n"); >> >> + 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 (CRASHDEBUG(1)) >> + fprintf(fp, "boot_date: %lx: %s\n", >> + kt->boot_date.tv_sec, strip_linefeeds(ctime(&kt->boot_date.tv_sec))); >> >> verify_version(); >> >> @@ -4912,9 +4922,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; >> @@ -5154,7 +5167,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); >> } >> -- >> 1.8.3.1 >> >> >> >> > > > > ------------------------------ > > Message: 2 > Date: Sun, 19 Apr 2020 15:48:55 -0400 (EDT) > From: Dave Anderson <anderson(a)redhat.com&gt; > To: "Discussion list for crash utility usage, maintenance and > development" <crash-utility(a)redhat.com&gt; > Subject: Re: [Crash-utility] [PATCH] add log -T option to display the > message text with human readable timestamp > Message-ID: > <2105444223.23908999.1587325735354.JavaMail.zimbra(a)redhat.com&gt; > Content-Type: text/plain; charset=utf-8 > > > FWIW, I tried it on another RHEL7 machine running live, > but then also on a RHEL8 kernel dumpfile, and they all hang: > > $ crash vmlinux vmcore > > crash 7.2.9rc13 > Copyright (C) 2002-2020 Red Hat, Inc. > Copyright (C) 2004, 2005, 2006, 2010 IBM Corporation > Copyright (C) 1999-2006 Hewlett-Packard Co > Copyright (C) 2005, 2006, 2011, 2012 Fujitsu Limited > Copyright (C) 2006, 2007 VA Linux Systems Japan K.K. > Copyright (C) 2005, 2011 NEC Corporation > Copyright (C) 1999, 2002, 2007 Silicon Graphics, Inc. > Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc. > This program is free software, covered by the GNU General Public License, > and you are welcome to change it and/or distribute copies of it under > certain conditions. Enter "help copying" to see the conditions. > This program has absolutely no warranty. Enter "help warranty" for details. > > GNU gdb (GDB) 7.6 > Copyright (C) 2013 Free Software Foundation, Inc. > License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> > This is free software: you are free to change and redistribute it. > There is NO WARRANTY, to the extent permitted by law. Type "show copying" > and "show warranty" for details. > This GDB was configured as "x86_64-unknown-linux-gnu"... > > WARNING: kernel relocated [950MB]: patching 94929 gdb minimal_symbol values > > crash: start patch... > > > > ----- Original Message ----- >> >> >> ----- 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(a)laoqinren.net&gt; >> >> Did you attempt this patch on a live system? Because your patch to >> kernel_init() hangs the session. I didn't bother to investigate beyond >> adding these two debug statements around your addition to kernel_init(): >> >> error(INFO, "start patch...\n"); >> 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; >> error(INFO, "end patch...\n"); >> >> And that's where it hangs: >> >> $ ./crash >> >> crash 7.2.9rc13 >> Copyright (C) 2002-2020 Red Hat, Inc. >> Copyright (C) 2004, 2005, 2006, 2010 IBM Corporation >> Copyright (C) 1999-2006 Hewlett-Packard Co >> Copyright (C) 2005, 2006, 2011, 2012 Fujitsu Limited >> Copyright (C) 2006, 2007 VA Linux Systems Japan K.K. >> Copyright (C) 2005, 2011 NEC Corporation >> Copyright (C) 1999, 2002, 2007 Silicon Graphics, Inc. >> Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc. >> This program is free software, covered by the GNU General Public License, >> and you are welcome to change it and/or distribute copies of it under >> certain conditions. Enter "help copying" to see the conditions. >> This program has absolutely no warranty. Enter "help warranty" for >> details. >> >> GNU gdb (GDB) 7.6 >> Copyright (C) 2013 Free Software Foundation, Inc. >> License GPLv3+: GNU GPL version 3 or later >> <http://gnu.org/licenses/gpl.html> >> This is free software: you are free to change and redistribute it. >> There is NO WARRANTY, to the extent permitted by law. Type "show copying" >> and "show warranty" for details. >> This GDB was configured as "x86_64-unknown-linux-gnu"... >> >> WARNING: kernel relocated [796MB]: patching 85687 gdb minimal_symbol values >> >> crash: start patch... >> >> <hang> >> >> And it shows a cpu spinning at 100%: >> >> $ top >> top - 15:26:43 up 38 days, 3:41, 5 users, load average: 1.00, 0.89, 0.65 >> Tasks: 280 total, 2 running, 278 sleeping, 0 stopped, 0 zombie >> %Cpu(s): 3.9 us, 8.7 sy, 0.0 ni, 87.3 id, 0.0 wa, 0.0 hi, 0.0 si, >> 0.0 st >> KiB Mem : 15907600 total, 455876 free, 1232832 used, 14218892 buff/cache >> KiB Swap: 8060924 total, 7395580 free, 665344 used. 14176220 avail Mem >> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND >> 26668 root 20 0 350268 213688 5680 R 100.0 1.3 5:42.70 crash >> 1707 root 20 0 115692 1184 688 S 0.3 0.0 2:16.52 >> ksmtuned >> 12852 anderson 20 0 4235240 274608 20320 S 0.3 1.7 601:46.85 >> gnome-shell >> 13060 anderson 20 0 804924 14100 3744 S 0.3 0.1 118:44.59 >> gsd-color >> 27045 anderson 20 0 172452 2532 1648 R 0.3 0.0 0:00.08 top >> 1 root 20 0 210504 5592 3224 S 0.0 0.0 18:14.19 systemd >> ... >> >> I'll let you figure it out... >> >> Dave >> >> >> >> >> >> >>> --- >>> defs.h | 2 ++ >>> help.c | 28 +++++++++++++++++++++++++++- >>> kernel.c | 22 ++++++++++++++++++++-- >>> 3 files changed, 49 insertions(+), 3 deletions(-) >>> >>> diff --git a/defs.h b/defs.h >>> index d8eda5e..1644dbd 100644 >>> --- a/defs.h/ >>> +++ b/defs.h >>> @@ -689,6 +689,7 @@ struct kernel_table { /* kernel data >>> */ >>> ulong kernel_module; >>> int mods_installed; >>> struct timespec date; >>> + struct timespec boot_date; >>> char proc_version[BUFSIZE]; >>> struct new_utsname utsname; >>> uint kernel_version[3]; >>> @@ -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..016d8d9 100644 >>> --- a/kernel.c >>> +++ b/kernel.c >>> @@ -111,6 +111,8 @@ kernel_init() >>> char *irq_desc_type_name; >>> ulong pv_init_ops;/ >>> struct gnu_request req; >>> + ulonglong uptime_jiffies; >>> + ulong uptime_sec; >>> >>> if (pc->flags & KERNEL_DEBUG_QUERY) >>> return; >>> @@ -294,6 +296,14 @@ kernel_init() >>> } else >>> error(INFO, "cannot determine base kernel version\n"); >>> >>> + 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 (CRASHDEBUG(1)) >>> + fprintf(fp, "boot_date: %lx: %s\n", >>> + kt->boot_date.tv_sec, strip_linefeeds(ctime(&kt->boot_date.tv_sec))); >>> >>> verify_version(); >>> >>> @@ -4912,9 +4922,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; >>> @@ -5154,7 +5167,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); >>> } >>> -- >>> 1.8.3.1 >>> >>> >>> >>> >> >> -- >> Crash-utility mailing list >> Crash-utility(a)redhat.com >> https://www.redhat.com/mailman/listinfo/crash-utility >> > > > > ------------------------------ > > Message: 3 > Date: Sun, 19 Apr 2020 20:01:12 +0000 > From: "Moore, Martin (Linux ERT)" <martin.moore(a)hpe.com&gt; > To: "Discussion list for crash utility usage, maintenance and > development" <crash-utility(a)redhat.com&gt;, &quot;anderson(a)redhat.com&quot; > <anderson(a)redhat.com&gt; > Subject: Re: [Crash-utility] [PATCH] add log -T option to display the > message text with human readable timestamp > Message-ID: > <AT5PR8401MB05480CDBEEE71C6F900654B991D70(a)AT5PR8401MB0548.NAMPRD84.PROD.OUTLOOK.COM&gt; > > Content-Type: text/plain; charset=WINDOWS-1252 > > Just to mention an alternative possibility, the pykdump extension to crash (https://sourceforge.net/projects/pykdump/) includes the 'tslog' command to accomplish this. > > Martin Moore > Linux Engineering Resolution Team > HPE Pointnext Services > Hewlett Packard Enterprise > > Martin.Moore(a)hpe.com? > 8AM-5PM EDT (GMT-4) Monday-Friday > Manager: Becky McBride (becky.mcbride(a)hpe.com) > > -----Original Message----- > From: crash-utility-bounces(a)redhat.com <crash-utility-bounces(a)redhat.com&gt; On Behalf Of Wang Long > Sent: Saturday, April 18, 2020 10:21 PM > To: anderson(a)redhat.com; crash-utility(a)redhat.com > Subject: [Crash-utility] [PATCH] add log -T option to display the message text with human readable timestamp > > 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(a)laoqinren.net&gt; > --- > defs.h | 2 ++ > help.c | 28 +++++++++++++++++++++++++++- > kernel.c | 22 ++++++++++++++++++++-- > 3 files changed, 49 insertions(+), 3 deletions(-) > > diff --git a/defs.h b/defs.h > index d8eda5e..1644dbd 100644 > --- a/defs.h > +++ b/defs.h > @@ -689,6 +689,7 @@ struct kernel_table { /* kernel data */ > ulong kernel_module; > int mods_installed; > struct timespec date; > + struct timespec boot_date; > char proc_version[BUFSIZE]; > struct new_utsname utsname; > uint kernel_version[3]; > @@ -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..016d8d9 100644 > --- a/kernel.c > +++ b/kernel.c > @@ -111,6 +111,8 @@ kernel_init() > char *irq_desc_type_name; > ulong pv_init_ops; > struct gnu_request req; > + ulonglong uptime_jiffies; > + ulong uptime_sec; > > if (pc->flags & KERNEL_DEBUG_QUERY) > return; > @@ -294,6 +296,14 @@ kernel_init() > } else > error(INFO, "cannot determine base kernel version\n"); > > + 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 (CRASHDEBUG(1)) > + fprintf(fp, "boot_date: %lx: %s\n", > + kt->boot_date.tv_sec, > +strip_linefeeds(ctime(&kt->boot_date.tv_sec))); > > verify_version(); > > @@ -4912,9 +4922,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; > @@ -5154,7 +5167,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); > } > -- > 1.8.3.1 > > > > > -- > Crash-utility mailing list > Crash-utility(a)redhat.com > https://www.redhat.com/mailman/listinfo/crash-utility > > > > > ------------------------------ > > -- > Crash-utility mailing list > Crash-utility(a)redhat.com > https://www.redhat.com/mailman/listinfo/crash-utility > > End of Crash-utility Digest, Vol 175, Issue 27 > ********************************************** > ------------------------------ -- Crash-utility mailing list Crash-utility(a)redhat.com https://www.redhat.com/mailman/listinfo/crash-utility End of Crash-utility Digest, Vol 175, Issue 28 **********************************************