2017-06-27 10:29:35

by Masami Hiramatsu

[permalink] [raw]
Subject: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

Use md5sum so that it takes less time of checking
trace logs update. Since busybox tail/cat takes too
long time to read the trace log, this uses md5sum
to check whether trace log is updated or not.

Signed-off-by: Masami Hiramatsu <[email protected]>
---
.../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
index 9cf3852..7a9ab4f 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
@@ -103,11 +103,11 @@ if [ $on != "0" ]; then
fail "Tracing is not off"
fi

-line1=`cat trace | tail -1`
+csum1=`md5sum trace`
sleep $SLEEP_TIME
-line2=`cat trace | tail -1`
+csum2=`md5sum trace`

-if [ "$line1" != "$line2" ]; then
+if [ "$csum1" != "$csum2" ]; then
fail "Tracing file is still changing"
fi



2017-06-28 14:00:55

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On 06/27/2017 04:28 AM, Masami Hiramatsu wrote:
> Use md5sum so that it takes less time of checking
> trace logs update. Since busybox tail/cat takes too
> long time to read the trace log, this uses md5sum
> to check whether trace log is updated or not.
>
> Signed-off-by: Masami Hiramatsu <[email protected]>

Applied to linux-kselftest next for 4.13-rc1

thanks,
-- Shuah

> ---
> .../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> index 9cf3852..7a9ab4f 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> @@ -103,11 +103,11 @@ if [ $on != "0" ]; then
> fail "Tracing is not off"
> fi
>
> -line1=`cat trace | tail -1`
> +csum1=`md5sum trace`
> sleep $SLEEP_TIME
> -line2=`cat trace | tail -1`
> +csum2=`md5sum trace`
>
> -if [ "$line1" != "$line2" ]; then
> +if [ "$csum1" != "$csum2" ]; then
> fail "Tracing file is still changing"
> fi
>
>
>
>

2017-06-28 14:17:38

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Tue, 27 Jun 2017 19:28:32 +0900
Masami Hiramatsu <[email protected]> wrote:

> Use md5sum so that it takes less time of checking
> trace logs update. Since busybox tail/cat takes too
> long time to read the trace log, this uses md5sum
> to check whether trace log is updated or not.

How much faster is md5sum? I can see this causing issues in other
environments.

-- Steve

>
> Signed-off-by: Masami Hiramatsu <[email protected]>
> ---
> .../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> index 9cf3852..7a9ab4f 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> @@ -103,11 +103,11 @@ if [ $on != "0" ]; then
> fail "Tracing is not off"
> fi
>
> -line1=`cat trace | tail -1`
> +csum1=`md5sum trace`
> sleep $SLEEP_TIME
> -line2=`cat trace | tail -1`
> +csum2=`md5sum trace`
>
> -if [ "$line1" != "$line2" ]; then
> +if [ "$csum1" != "$csum2" ]; then
> fail "Tracing file is still changing"
> fi
>

2017-06-28 14:30:45

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On 06/28/2017 08:17 AM, Steven Rostedt wrote:
> On Tue, 27 Jun 2017 19:28:32 +0900
> Masami Hiramatsu <[email protected]> wrote:
>
>> Use md5sum so that it takes less time of checking
>> trace logs update. Since busybox tail/cat takes too
>> long time to read the trace log, this uses md5sum
>> to check whether trace log is updated or not.
>
> How much faster is md5sum? I can see this causing issues in other
> environments.
>
> -- Steve

Sorry Steve. I pulled this into linux-ksefltest next. Are you concerned
about any specific environments? I can try this out and see if it is a
problem.

thanks,
-- Shuah

>
>>
>> Signed-off-by: Masami Hiramatsu <[email protected]>
>> ---
>> .../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
>> 1 file changed, 3 insertions(+), 3 deletions(-)
>>
>> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
>> index 9cf3852..7a9ab4f 100644
>> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
>> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
>> @@ -103,11 +103,11 @@ if [ $on != "0" ]; then
>> fail "Tracing is not off"
>> fi
>>
>> -line1=`cat trace | tail -1`
>> +csum1=`md5sum trace`
>> sleep $SLEEP_TIME
>> -line2=`cat trace | tail -1`
>> +csum2=`md5sum trace`
>>
>> -if [ "$line1" != "$line2" ]; then
>> +if [ "$csum1" != "$csum2" ]; then
>> fail "Tracing file is still changing"
>> fi
>>
>
>
>

2017-06-28 14:59:42

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Wed, 28 Jun 2017 08:30:24 -0600
Shuah Khan <[email protected]> wrote:

> On 06/28/2017 08:17 AM, Steven Rostedt wrote:
> > On Tue, 27 Jun 2017 19:28:32 +0900
> > Masami Hiramatsu <[email protected]> wrote:
> >
> >> Use md5sum so that it takes less time of checking
> >> trace logs update. Since busybox tail/cat takes too
> >> long time to read the trace log, this uses md5sum
> >> to check whether trace log is updated or not.
> >
> > How much faster is md5sum? I can see this causing issues in other
> > environments.
> >
> > -- Steve
>
> Sorry Steve. I pulled this into linux-ksefltest next. Are you concerned
> about any specific environments? I can try this out and see if it is a
> problem.

Yes please. I should probably do some playing too. I would like to fix
that test anyway, as it is one of the longer ones as I do a lot of
"paranoid checks". That is, I may go overboard in testing if tracing is
off or not, by checking to make sure its off using different tactics.

-- Steve

2017-06-28 15:31:05

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On 06/28/2017 08:59 AM, Steven Rostedt wrote:
> On Wed, 28 Jun 2017 08:30:24 -0600
> Shuah Khan <[email protected]> wrote:
>
>> On 06/28/2017 08:17 AM, Steven Rostedt wrote:
>>> On Tue, 27 Jun 2017 19:28:32 +0900
>>> Masami Hiramatsu <[email protected]> wrote:
>>>
>>>> Use md5sum so that it takes less time of checking
>>>> trace logs update. Since busybox tail/cat takes too
>>>> long time to read the trace log, this uses md5sum
>>>> to check whether trace log is updated or not.
>>>
>>> How much faster is md5sum? I can see this causing issues in other
>>> environments.
>>>
>>> -- Steve
>>
>> Sorry Steve. I pulled this into linux-ksefltest next. Are you concerned
>> about any specific environments? I can try this out and see if it is a
>> problem.
>
> Yes please. I should probably do some playing too. I would like to fix
> that test anyway, as it is one of the longer ones as I do a lot of
> "paranoid checks". That is, I may go overboard in testing if tracing is
> off or not, by checking to make sure its off using different tactics.
>

Please let me know how your trials go. I have a few things I have to get
to before I get around to trying this patch.

thanks,
-- Shuah

2017-06-29 20:21:45

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On 06/28/2017 09:30 AM, Shuah Khan wrote:
> On 06/28/2017 08:59 AM, Steven Rostedt wrote:
>> On Wed, 28 Jun 2017 08:30:24 -0600
>> Shuah Khan <[email protected]> wrote:
>>
>>> On 06/28/2017 08:17 AM, Steven Rostedt wrote:
>>>> On Tue, 27 Jun 2017 19:28:32 +0900
>>>> Masami Hiramatsu <[email protected]> wrote:
>>>>
>>>>> Use md5sum so that it takes less time of checking
>>>>> trace logs update. Since busybox tail/cat takes too
>>>>> long time to read the trace log, this uses md5sum
>>>>> to check whether trace log is updated or not.
>>>>
>>>> How much faster is md5sum? I can see this causing issues in other
>>>> environments.
>>>>
>>>> -- Steve
>>>
>>> Sorry Steve. I pulled this into linux-ksefltest next. Are you concerned
>>> about any specific environments? I can try this out and see if it is a
>>> problem.
>>
>> Yes please. I should probably do some playing too. I would like to fix
>> that test anyway, as it is one of the longer ones as I do a lot of
>> "paranoid checks". That is, I may go overboard in testing if tracing is
>> off or not, by checking to make sure its off using different tactics.
>>
>
> Please let me know how your trials go. I have a few things I have to get
> to before I get around to trying this patch.
>
> thanks,
> -- Shuah

Hi Steve/Masami,

I tested this patch on my test system running 4.12-rc7 and didn't see any
problems. I am going to leave this in the linux-kselftest next for 4.13-rc1.
Please let me if you think I should drop it.

thanks,
-- Shuah

2017-06-30 14:50:04

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Thu, 29 Jun 2017 14:21:41 -0600
Shuah Khan <[email protected]> wrote:
\
> Hi Steve/Masami,
>
> I tested this patch on my test system running 4.12-rc7 and didn't see any
> problems. I am going to leave this in the linux-kselftest next for 4.13-rc1.
> Please let me if you think I should drop it.

I played a little with it.

Acked-by: Steven Rostedt (VMware) <[email protected]>

-- Steve

2017-06-30 16:53:19

by Shuah Khan

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On 06/30/2017 08:49 AM, Steven Rostedt wrote:
> On Thu, 29 Jun 2017 14:21:41 -0600
> Shuah Khan <[email protected]> wrote:
> \
>> Hi Steve/Masami,
>>
>> I tested this patch on my test system running 4.12-rc7 and didn't see any
>> problems. I am going to leave this in the linux-kselftest next for 4.13-rc1.
>> Please let me if you think I should drop it.
>
> I played a little with it.
>
> Acked-by: Steven Rostedt (VMware) <[email protected]>
>
> -- Steve
>
>

Thanks. Applied your Ack now to linux-kselftest next.

-- Shuah

2017-06-30 18:51:09

by Denys Vlasenko

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Tue, Jun 27, 2017 at 12:28 PM, Masami Hiramatsu <[email protected]> wrote:
> Use md5sum so that it takes less time of checking
> trace logs update. Since busybox tail/cat takes too
> long time to read the trace log, this uses md5sum
> to check whether trace log is updated or not.
>
> Signed-off-by: Masami Hiramatsu <[email protected]>
> ---
> .../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> index 9cf3852..7a9ab4f 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> @@ -103,11 +103,11 @@ if [ $on != "0" ]; then
> fail "Tracing is not off"
> fi
>
> -line1=`cat trace | tail -1`
> +csum1=`md5sum trace`
> sleep $SLEEP_TIME
> -line2=`cat trace | tail -1`
> +csum2=`md5sum trace`

If you replace that with "tail -1 <trace", this code
in busybox will be used:

off_t current = lseek(fd, 0, SEEK_END);
if (current > 0) {
...
#if 1 /* This is technically incorrect for *LONG* strings, but very useful */
/* Optimizing count-lines case if the
file is seekable.
* We assume the lines are <64k.
* (Users complain that tail takes too long
* on multi-gigabyte files) */
off = (count | 0xf); /* for small
counts, be more paranoid */
if (off > (INT_MAX / (64*1024)))
off = (INT_MAX / (64*1024));
current -= off * (64*1024);
if (current < 0)
current = 0;
xlseek(fd, current, SEEK_SET);
#endif

Example: "tail -1 10GB_FILE" seeks back ~1 mbyte and looks for the last line:

lseek(3, 0, SEEK_END) = 10991787403
lseek(3, 10990804363, SEEK_SET) = 10990804363
read(3, "\0\0020d\340\326\0\0\0\0020e\6\364\0\0\0\0020eMI\0\0\0\0020el\210\0\0"...,
8192) = 8192
read(3, "\0\0021\"p\321\0\0\0\0021\"\216\31\0\0\0\0021\"\254q\0\0\0\0021\"\367u\0\0"...,
8192) = 8192
read(3, "\0\0021\342\216\302\0\0\0\0021\342\2243\0\0\0\0021\342\266T\0\0\0\0021\342\326\v\0\0"...,
8192) = 8192
...
read(3, "\0\0\2\211\3272\211\0\0\0\2\211\3277\235\0\0\0\2\211\327mx\0\0\0\2\211\327\224\22\0"...,
11841) = 11841
read(3, "\0\2\212\357\366\306\0\0\0\2\212\360`\232\0\0\0\2\212\360w\262\0\0\0\2\212\360\354\365\0\0"...,
12512) = 12512
read(3, "\0\2\214uL\3\0\0\0\2\214unc\0\0\0\2\214w_\373\0\0\0\2\214wn\6\0\0"...,
11176) = 8424
read(3, "", 2752) = 0

2017-06-30 19:03:20

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Fri, 30 Jun 2017 20:50:45 +0200
Denys Vlasenko <[email protected]> wrote:

> On Tue, Jun 27, 2017 at 12:28 PM, Masami Hiramatsu <[email protected]> wrote:
> > Use md5sum so that it takes less time of checking
> > trace logs update. Since busybox tail/cat takes too
> > long time to read the trace log, this uses md5sum
> > to check whether trace log is updated or not.
> >
> > Signed-off-by: Masami Hiramatsu <[email protected]>
> > ---
> > .../test.d/ftrace/func_traceonoff_triggers.tc | 6 +++---
> > 1 file changed, 3 insertions(+), 3 deletions(-)
> >
> > diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> > index 9cf3852..7a9ab4f 100644
> > --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> > +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
> > @@ -103,11 +103,11 @@ if [ $on != "0" ]; then
> > fail "Tracing is not off"
> > fi
> >
> > -line1=`cat trace | tail -1`
> > +csum1=`md5sum trace`
> > sleep $SLEEP_TIME
> > -line2=`cat trace | tail -1`
> > +csum2=`md5sum trace`
>
> If you replace that with "tail -1 <trace", this code
> in busybox will be used:
>
> off_t current = lseek(fd, 0, SEEK_END);

The trace file is a kernel pseudo file that prevents lseek. Now what
you could do is:

cat trace > tempfile
csum1=`tail -1 <tempfile`

But then we need to make sure to clean up the files.

-- Steve

2017-07-03 04:19:17

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH] selftests: ftrace: Use md5sum to take less time of checking logs

On Fri, 30 Jun 2017 10:53:15 -0600
Shuah Khan <[email protected]> wrote:

> On 06/30/2017 08:49 AM, Steven Rostedt wrote:
> > On Thu, 29 Jun 2017 14:21:41 -0600
> > Shuah Khan <[email protected]> wrote:
> > \
> >> Hi Steve/Masami,
> >>
> >> I tested this patch on my test system running 4.12-rc7 and didn't see any
> >> problems. I am going to leave this in the linux-kselftest next for 4.13-rc1.
> >> Please let me if you think I should drop it.
> >
> > I played a little with it.
> >
> > Acked-by: Steven Rostedt (VMware) <[email protected]>
> >
> > -- Steve
> >
> >
>
> Thanks. Applied your Ack now to linux-kselftest next.

Thanks Steve and Shuah!

--
Masami Hiramatsu <[email protected]>