Optionally dump boottime on the mtd device in the form of
<0>[ 0.000000] Boot time mm/dd/yyyy hh:mm:ss
Time-stamps of oops messages are in seconds since boottime. Recording also
the boottime helps correlating oopses with other events having occured at
the same time. This correlation will be otherwise lost after (multiple)
reboots.
Signed-off-by: Stefan M Schaeckeler <[email protected]>
---
drivers/mtd/mtdoops.c | 38 +++++++++++++++++++++++++++++++++++---
1 file changed, 35 insertions(+), 3 deletions(-)
diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
index 9f25111..11f93aa 100644
--- a/drivers/mtd/mtdoops.c
+++ b/drivers/mtd/mtdoops.c
@@ -54,6 +54,11 @@ module_param(dump_oops, int, 0600);
MODULE_PARM_DESC(dump_oops,
"set to 1 to dump oopses, 0 to only dump panics (default 1)");
+static bool dump_boottime = false;
+module_param(dump_boottime, bool, 0400);
+MODULE_PARM_DESC(dump_boottime,
+ "set to 1 to dump boottime, 0 to disable (default 0)");
+
static struct mtdoops_context {
struct kmsg_dumper dump;
@@ -69,6 +74,10 @@ static struct mtdoops_context {
void *oops_buf;
} oops_cxt;
+/* fake kernel message syslog level and monotonic timestamp */
+#define boottime_prefix "<0>[ 0.000000] Boot time "
+static char boottime[100] = {0};
+
static void mark_page_used(struct mtdoops_context *cxt, int page)
{
set_bit(page, cxt->oops_page_used);
@@ -285,13 +294,17 @@ static void mtdoops_do_dump(struct kmsg_dumper *dumper,
{
struct mtdoops_context *cxt = container_of(dumper,
struct mtdoops_context, dump);
+ u8 boot_len = strlen(boottime); /* 0 if dump_boottime is not set */
/* Only dump oopses if dump_oops is set */
if (reason == KMSG_DUMP_OOPS && !dump_oops)
return;
- kmsg_dump_get_buffer(dumper, true, cxt->oops_buf + MTDOOPS_HEADER_SIZE,
- record_size - MTDOOPS_HEADER_SIZE, NULL);
+ strncpy(cxt->oops_buf + MTDOOPS_HEADER_SIZE, boottime, boot_len);
+
+ kmsg_dump_get_buffer(dumper, true, cxt->oops_buf + MTDOOPS_HEADER_SIZE +
+ boot_len, record_size - (MTDOOPS_HEADER_SIZE +
+ boot_len), NULL);
/* Panics must be written immediately */
if (reason != KMSG_DUMP_OOPS)
@@ -350,7 +363,13 @@ static void mtdoops_notify_add(struct mtd_info *mtd)
cxt->mtd = mtd;
cxt->oops_pages = (int)mtd->size / record_size;
find_next_position(cxt);
- printk(KERN_INFO "mtdoops: Attached to MTD device %d\n", mtd->index);
+ if (dump_boottime) {
+ printk(KERN_INFO "mtdoops: Attached to MTD device %d "
+ "dumping boottime\n", mtd->index);
+ } else {
+ printk(KERN_INFO "mtdoops: Attached to MTD device %d "
+ "not dumping boottime\n", mtd->index);
+ }
}
static void mtdoops_notify_remove(struct mtd_info *mtd)
@@ -379,6 +398,19 @@ static int __init mtdoops_init(void)
struct mtdoops_context *cxt = &oops_cxt;
int mtd_index;
char *endp;
+ struct timespec64 bt;
+ struct tm tm_val;
+
+ if (dump_boottime) {
+ /* Precompute boot time ahead of an oops */
+ getboottime64(&bt);
+ time_to_tm(bt.tv_sec, 0, &tm_val);
+
+ snprintf(boottime, sizeof(boottime),
+ boottime_prefix "%02d/%02d/%4d %02d:%02d:%02d\n",
+ tm_val.tm_mon + 1, tm_val.tm_mday, tm_val.tm_year + 1900,
+ tm_val.tm_hour, tm_val.tm_min, tm_val.tm_sec);
+ }
if (strlen(mtddev) == 0) {
printk(KERN_ERR "mtdoops: mtd device (mtddev=name/number) must be supplied\n");
--
2.10.3.dirty
Stefan,
Am Sonntag, 20. Mai 2018, 05:39:40 CEST schrieb Stefan M Schaeckeler:
> Optionally dump boottime on the mtd device in the form of
>
> <0>[ 0.000000] Boot time mm/dd/yyyy hh:mm:ss
>
> Time-stamps of oops messages are in seconds since boottime. Recording also
> the boottime helps correlating oopses with other events having occured at
> the same time. This correlation will be otherwise lost after (multiple)
> reboots.
I get the use-case, but why is this only for mtdoops?
IMHO this needs to go into generic code such that all kmsg dumpers can
benefit from it.
Thanks,
//richard
Hi Stefan,
Thank you for the patch! Perhaps something to improve:
[auto build test WARNING on mtd/master]
[also build test WARNING on v4.17-rc5 next-20180517]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]
url: https://github.com/0day-ci/linux/commits/Stefan-M-Schaeckeler/mtd-mtdoops-optionally-dump-boottime/20180521-030143
base: git://git.infradead.org/linux-mtd.git master
config: x86_64-randconfig-x011-201820 (attached as .config)
compiler: gcc-7 (Debian 7.3.0-16) 7.3.0
reproduce:
# save the attached .config to linux build tree
make ARCH=x86_64
All warnings (new ones prefixed by >>):
drivers//mtd/mtdoops.c: In function 'mtdoops_init':
>> drivers//mtd/mtdoops.c:78:25: warning: format '%d' expects argument of type 'int', but argument 6 has type 'long int' [-Wformat=]
#define boottime_prefix "<0>[ 0.000000] Boot time "
^
>> drivers//mtd/mtdoops.c:410:8: note: in expansion of macro 'boottime_prefix'
boottime_prefix "%02d/%02d/%4d %02d:%02d:%02d\n",
^~~~~~~~~~~~~~~
drivers//mtd/mtdoops.c:410:37: note: format string is defined here
boottime_prefix "%02d/%02d/%4d %02d:%02d:%02d\n",
~~^
%4ld
vim +/boottime_prefix +410 drivers//mtd/mtdoops.c
395
396 static int __init mtdoops_init(void)
397 {
398 struct mtdoops_context *cxt = &oops_cxt;
399 int mtd_index;
400 char *endp;
401 struct timespec64 bt;
402 struct tm tm_val;
403
404 if (dump_boottime) {
405 /* Precompute boot time ahead of an oops */
406 getboottime64(&bt);
407 time_to_tm(bt.tv_sec, 0, &tm_val);
408
409 snprintf(boottime, sizeof(boottime),
> 410 boottime_prefix "%02d/%02d/%4d %02d:%02d:%02d\n",
411 tm_val.tm_mon + 1, tm_val.tm_mday, tm_val.tm_year + 1900,
412 tm_val.tm_hour, tm_val.tm_min, tm_val.tm_sec);
413 }
414
415 if (strlen(mtddev) == 0) {
416 printk(KERN_ERR "mtdoops: mtd device (mtddev=name/number) must be supplied\n");
417 return -EINVAL;
418 }
419 if ((record_size & 4095) != 0) {
420 printk(KERN_ERR "mtdoops: record_size must be a multiple of 4096\n");
421 return -EINVAL;
422 }
423 if (record_size < 4096) {
424 printk(KERN_ERR "mtdoops: record_size must be over 4096 bytes\n");
425 return -EINVAL;
426 }
427
428 /* Setup the MTD device to use */
429 cxt->mtd_index = -1;
430 mtd_index = simple_strtoul(mtddev, &endp, 0);
431 if (*endp == '\0')
432 cxt->mtd_index = mtd_index;
433
434 cxt->oops_buf = vmalloc(record_size);
435 if (!cxt->oops_buf) {
436 printk(KERN_ERR "mtdoops: failed to allocate buffer workspace\n");
437 return -ENOMEM;
438 }
439 memset(cxt->oops_buf, 0xff, record_size);
440
441 INIT_WORK(&cxt->work_erase, mtdoops_workfunc_erase);
442 INIT_WORK(&cxt->work_write, mtdoops_workfunc_write);
443
444 register_mtd_user(&mtdoops_notifier);
445 return 0;
446 }
447
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all Intel Corporation
Hello Richard and others,
> I get the use-case, but why is this only for mtdoops?
Powerpc's nvram module also stores oops messages and does so by adding an
additional timestamp, as well (search for kmsg_dump_get_buffer() in
arch/powerpc/kernel/nvram_64.c).
This timestamp is the number of seconds since 1970 and stored as a 64 bit
integer in the nvram header. Basically, the last kmesg timestamp is a few ms
less than this additionally stored timestamp. Recording boottime would be more
elegant, I guess.
> IMHO this needs to go into generic code such that all kmsg dumpers can
> benefit from it.
This would be not that easy:
#1 kmsg_dump_get_buffer(...size...) returns the most recent <size> bytes.
Consecutive calls return older chunks. It would be natural to return the
boottime as the first line, e.g. in the last call, but some clients such as
mtdoops call kmsg_dump_get_buffer() only once. The returned buffer may be
complete including boottime, or not.
#2 consistency with other clients: nvram_64.c has the same requirement of
storing a kind of wall-time but does it in a completely different way: no
readable ascii text timestamp preprended to the kmsg buffer but a 64 bit
timestamp in its header. Note, I don't think we should make mtdoops behave like
nvram_64.c by storing the timestamp as a 64 bit integer (in its header) b/c
most people do a cat or string of the mtd device /dev/mtdX and a 64 bit integer
would just read as garbage.
I hope we can have separate implementations for recording additional
timestamps. Later, I'll send a patch with stylistic changes unless we
completely disagree on how to move forward.
Stefan
Stefan,
Am Montag, 21. Mai 2018, 04:29:24 CEST schrieb Stefan Schaeckeler:
> Hello Richard and others,
>
> > I get the use-case, but why is this only for mtdoops?
>
> Powerpc's nvram module also stores oops messages and does so by adding an
> additional timestamp, as well (search for kmsg_dump_get_buffer() in
> arch/powerpc/kernel/nvram_64.c).
Just one more reason to make it generic.
> This timestamp is the number of seconds since 1970 and stored as a 64 bit
> integer in the nvram header. Basically, the last kmesg timestamp is a few ms
> less than this additionally stored timestamp. Recording boottime would be more
> elegant, I guess.
>
>
> > IMHO this needs to go into generic code such that all kmsg dumpers can
> > benefit from it.
>
> This would be not that easy:
>
> #1 kmsg_dump_get_buffer(...size...) returns the most recent <size> bytes.
> Consecutive calls return older chunks. It would be natural to return the
> boottime as the first line, e.g. in the last call, but some clients such as
> mtdoops call kmsg_dump_get_buffer() only once. The returned buffer may be
> complete including boottime, or not.
>
> #2 consistency with other clients: nvram_64.c has the same requirement of
> storing a kind of wall-time but does it in a completely different way: no
> readable ascii text timestamp preprended to the kmsg buffer but a 64 bit
> timestamp in its header. Note, I don't think we should make mtdoops behave like
> nvram_64.c by storing the timestamp as a 64 bit integer (in its header) b/c
> most people do a cat or string of the mtd device /dev/mtdX and a 64 bit integer
> would just read as garbage.
I think this is the perfect opportunity to talk with other kmesg dump users on
how to add a timestamp.
As last resort we can always do it in our own way but I think making it generic
is at lest worth a try...
> I hope we can have separate implementations for recording additional
> timestamps. Later, I'll send a patch with stylistic changes unless we
> completely disagree on how to move forward.
Both #1 and #2 aren't show-stoppers.
Thanks,
//richard