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

From: Denys Vlasenko
Date: Fri Jun 30 2017 - 14:52:16 EST


On Tue, Jun 27, 2017 at 12:28 PM, Masami Hiramatsu <mhiramat@xxxxxxxxxx> 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 <mhiramat@xxxxxxxxxx>
> ---
> .../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