Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1646704 > unrolled thread

[PATCH 2/2] Save current timestamp part of dmesg while writing oops message to pstore

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  [PATCH 2/2] Save current timestamp part of dmesg while writing oops message to pstore Ankit Kumar <ankit@linux.vnet.ibm.com> - 2017-05-22 12:30 +0200
    Re: [PATCH 2/2] Save current timestamp part of dmesg while writing  oops message to pstore Kees Cook <keescook@chromium.org> - 2017-05-23 02:00 +0200
      Re: [PATCH 2/2] Save current timestamp part of dmesg while writing  oops message to pstore Ankit Kumar <ankit@linux.vnet.ibm.com> - 2017-05-23 11:00 +0200

#1646704 — [PATCH 2/2] Save current timestamp part of dmesg while writing oops message to pstore

Currently on panic or Oops, kernel saves the last few bytes from dmesg
buffer to nvram. Usually kdump does capture kernel memory and provide
dmesg logs as well. But in some cases where kdump fails to capture
vmcore, the dmesg buffer stored in nvram/pstore turns out to be very
helpful in analyzing root cause.

Present code creates pstore dump file(/sys/fs/pstore/dmesg-***) based on
timestamp(retrieved from header). Current pstore code creates dump file
(/sys/fs/pstore/dmesg-***) with that timestamp. Dump file can be analyzed
based on file creation time and we can make out whether dump file has latest
data or not.

But when we transfer pstore dump file(/sys/fs/pstore/dmesg-***) to other
machine or collect file using some utilities(sosreport/supportconfig) then file
timestamp gets changed and hence by looking at device file (dmesg-***) we won't
be able to identify whether dump has latest data or not.

Above issue can be fixed if we also have timestamp(dump creation time) as
initial few bytes while capturing dmesg buffer to pstore dump file
(/sys/fs/pstore/dmesg-***).


This patch enhances pstore write code to also write timestamp as part of data.

Here is sample log of dump file:(/sys/fs/pstore/dmesg-***)
Oops#1 Part1 [timestamp:1494939359.590463]


Above timestamp can be converted to current zone using date command.
 #date -d @1494939359.590463
 # Tue May 16 18:25:59 IST 2017

Signed-off-by: Ankit Kumar <ankit@linux.vnet.ibm.com>
---
 fs/pstore/platform.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index 4fedf83..f65000e 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -501,6 +501,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 	unsigned long	flags = 0;
 	int		is_locked;
 	int		ret;
+	struct timespec timestamp;
 
 	why = get_reason_str(reason);
 
@@ -540,9 +541,11 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 			dst_size = psinfo->bufsize;
 		}
 
+		pstore_get_timestamp(&timestamp);
 		/* Write dump header. */
-		header_size = snprintf(dst, dst_size, "%s#%d Part%u\n", why,
-				 oopscount, part);
+		header_size = snprintf(dst, dst_size, "%s#%d Part%u [timestamp:%lu.%lu]\n",
+				why, oopscount, part, (long)timestamp.tv_sec,
+				(long)(timestamp.tv_nsec / 1000));
 		dst_size -= header_size;
 
 		/* Write dump contents. */
-- 
2.7.4

[toc] | [next] | [standalone]

#1647502 — Re: [PATCH 2/2] Save current timestamp part of dmesg while writing oops message to pstore

On Mon, May 22, 2017 at 3:20 AM, Ankit Kumar <ankit@linux.vnet.ibm.com> wrote:
> Currently on panic or Oops, kernel saves the last few bytes from dmesg
> buffer to nvram. Usually kdump does capture kernel memory and provide
> dmesg logs as well. But in some cases where kdump fails to capture
> vmcore, the dmesg buffer stored in nvram/pstore turns out to be very
> helpful in analyzing root cause.
>
> Present code creates pstore dump file(/sys/fs/pstore/dmesg-***) based on
> timestamp(retrieved from header). Current pstore code creates dump file
> (/sys/fs/pstore/dmesg-***) with that timestamp. Dump file can be analyzed
> based on file creation time and we can make out whether dump file has latest
> data or not.
>
> But when we transfer pstore dump file(/sys/fs/pstore/dmesg-***) to other
> machine or collect file using some utilities(sosreport/supportconfig) then file
> timestamp gets changed and hence by looking at device file (dmesg-***) we won't
> be able to identify whether dump has latest data or not.
>
> Above issue can be fixed if we also have timestamp(dump creation time) as
> initial few bytes while capturing dmesg buffer to pstore dump file
> (/sys/fs/pstore/dmesg-***).
>
>
> This patch enhances pstore write code to also write timestamp as part of data.
>
> Here is sample log of dump file:(/sys/fs/pstore/dmesg-***)
> Oops#1 Part1 [timestamp:1494939359.590463]

While I understand your rationale about possibly losing file timestamp
information in userspace, I think this is a solvable problem on the
collection side. If an additional header is needed, perhaps copy the
dmesg files like this:

for i in dmesg-*; do
    (stat --format=%y /sys/fs/pstore/$i; \
     cat /sys/fs/pstore/$i) > $collect_dir/$i
done

One of the primary concerns for pstore is the stored dump size, even
to the point of adding compression to the routines to squeeze out
every last bit of space. I'd really rather avoid adding the timestamp
to the stored data like this. It's up to the backends already to
efficiently store this, and it's exposed via the file timestamp, so I
really can't justify adding redundant data.

-Kees

-- 
Kees Cook
Pixel Security

[toc] | [prev] | [next] | [standalone]

#1647840 — Re: [PATCH 2/2] Save current timestamp part of dmesg while writing oops message to pstore

Hi Kees,



On Tuesday 23 May 2017 05:21 AM, Kees Cook wrote:
> On Mon, May 22, 2017 at 3:20 AM, Ankit Kumar <ankit@linux.vnet.ibm.com> wrote:
>> Currently on panic or Oops, kernel saves the last few bytes from dmesg
>> buffer to nvram. Usually kdump does capture kernel memory and provide
>> dmesg logs as well. But in some cases where kdump fails to capture
>> vmcore, the dmesg buffer stored in nvram/pstore turns out to be very
>> helpful in analyzing root cause.
>>
>> Present code creates pstore dump file(/sys/fs/pstore/dmesg-***) based on
>> timestamp(retrieved from header). Current pstore code creates dump file
>> (/sys/fs/pstore/dmesg-***) with that timestamp. Dump file can be analyzed
>> based on file creation time and we can make out whether dump file has latest
>> data or not.
>>
>> But when we transfer pstore dump file(/sys/fs/pstore/dmesg-***) to other
>> machine or collect file using some utilities(sosreport/supportconfig) then file
>> timestamp gets changed and hence by looking at device file (dmesg-***) we won't
>> be able to identify whether dump has latest data or not.
>>
>> Above issue can be fixed if we also have timestamp(dump creation time) as
>> initial few bytes while capturing dmesg buffer to pstore dump file
>> (/sys/fs/pstore/dmesg-***).
>>
>>
>> This patch enhances pstore write code to also write timestamp as part of data.
>>
>> Here is sample log of dump file:(/sys/fs/pstore/dmesg-***)
>> Oops#1 Part1 [timestamp:1494939359.590463]
> While I understand your rationale about possibly losing file timestamp
> information in userspace, I think this is a solvable problem on the
> collection side. If an additional header is needed, perhaps copy the
> dmesg files like this:
>
> for i in dmesg-*; do
>      (stat --format=%y /sys/fs/pstore/$i; \
>       cat /sys/fs/pstore/$i) > $collect_dir/$i
> done

Yes. We can handle this in userspace. But we wanted to see if we can add 
this as part of pstore
log itself.


> One of the primary concerns for pstore is the stored dump size,

I understand. How about adding timestamp to file name itself? Something 
like below

index 792a4e5..0837365 100644
--- a/fs/pstore/inode.c
+++ b/fs/pstore/inode.c
@@ -349,9 +349,10 @@ int pstore_mkfile(struct dentry *root, struct 
pstore_record *record)

         switch (record->type) {
         case PSTORE_TYPE_DMESG:
-               scnprintf(name, sizeof(name), "dmesg-%s-%lld%s",
+               scnprintf(name, sizeof(name), "dmesg-%s-%lld%s-%lu.%lu",
                           record->psi->name, record->id,
-                         record->compressed ? ".enc.z" : "");
+                         record->compressed ? ".enc.z" : "",
+                         record->time.tv_sec, record->time.tv_nsec / 1000);
                 break;
         case PSTORE_TYPE_CONSOLE:


~Ankit

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web