[Crash-utility] [PATCH] add log -T option to display the message text with human readable timestamp
Wang Long
w at laoqinren.net
Mon Apr 20 01:48:40 UTC 2020
On 20/4/2020 3:48 am, Dave Anderson wrote:
>
> FWIW, I tried it on another RHEL7 machine running live,
> but then also on a RHEL8 kernel dumpfile, and they all hang:
I apply this patch on RHEL7 virtual machine(VirtualBbox) and it work ok.
and on a RHEL7 kernel dumpfile, I found it hang after I send the patch.
and I debug it and found the machdep->hz == 0 on the following:
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;
because machdep-> hz has not been initialized here. divide by zero make
the cpu spinning at 100%.
I thought two solutions:
(1) add misc_init function after machdep_init(POST_INIT) call, and
calculate the value of kt-> boot_date in it.
read_in_kernel_config(IKCFG_INIT);
kernel_init();
machdep_init(POST_GDB);
vm_init();
machdep_init(POST_VM);
module_init();
help_init();
task_init();
vfs_init();
net_init();
dev_init();
machdep_init(POST_INIT);
+ misc_init();
(2) calculate the value of kt-> boot_date on cmd_log function, when we
call log command.
Dave, Which one do you like?
>
> $ 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 at laoqinren.net>
>>
>> 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 at redhat.com
>> https://www.redhat.com/mailman/listinfo/crash-utility
>>
>
>
More information about the Crash-utility
mailing list