----- 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@xxxxxxxxxxxxx>
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@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/crash-utility
