Re: [PATCH v4 1/7] fuzz: accelerate non-crash detection

[Qiuhao Li]

On Wed, 2021-01-06 at 23:18 -0500, Alexander Bulekov wrote:
> On 201229 1240, Qiuhao Li wrote:
> > We spend much time waiting for the timeout program during the
> > minimization
> > process until it passes a time limit. This patch hacks the CLOSED
> > (indicates
> > the redirection file closed) notification in QTest's output if it
> > doesn't
> > crash.
> > 
> > Test with quadrupled trace input at:
> >   https://bugs.launchpad.net/qemu/+bug/1890333/comments/1
> > 
> > Original version:
> >   real      1m37.246s
> >   user      0m13.069s
> >   sys       0m8.399s
> > 
> > Refined version:
> >   real      0m45.904s
> >   user      0m16.874s
> >   sys       0m10.042s
> > 
> > Signed-off-by: Qiuhao Li <Qiuhao.Li@outlook.com>
> > ---
> >  scripts/oss-fuzz/minimize_qtest_trace.py | 41 ++++++++++++++++--
> > ------
> >  1 file changed, 28 insertions(+), 13 deletions(-)
> > 
> > diff --git a/scripts/oss-fuzz/minimize_qtest_trace.py
> > b/scripts/oss-fuzz/minimize_qtest_trace.py
> > index 5e405a0d5f..aa69c7963e 100755
> > --- a/scripts/oss-fuzz/minimize_qtest_trace.py
> > +++ b/scripts/oss-fuzz/minimize_qtest_trace.py
> > @@ -29,30 +29,46 @@ whether the crash occred. Optionally, manually
> > set a string that idenitifes the
> >  crash by setting CRASH_TOKEN=
> >  """.format((sys.argv[0])))
> >  
> > +deduplication_note = """\n\
> > +Note: While trimming the input, sometimes the mutated trace
> > triggers a different
> > +crash output but indicates the same bug. Under this situation, our
> > minimizer is
> > +incapable of recognizing and stopped from removing it. In the
> > future, we may
> > +use a more sophisticated crash case deduplication method.
> > +\n"""
> > +
> >  def check_if_trace_crashes(trace, path):
> > -    global CRASH_TOKEN
> >      with open(path, "w") as tracefile:
> >          tracefile.write("".join(trace))
> >  
> > -    rc = subprocess.Popen("timeout -s 9 {timeout}s {qemu_path}
> > {qemu_args} 2>&1\
> > +    proc = subprocess.Popen("timeout {timeout}s {qemu_path}
> > {qemu_args} 2>&1\
> 
> Why remove the -s 9 here? I ran into a case where the minimizer got
> stuck on one iteration. Adding back "sigkill" to the timeout can be a
> safety net to catch those bad cases.
> -Alex

Hi Alex,

After reviewed this patch again, I think this get-stuck bug may be
caused by code:

-    return CRASH_TOKEN in output
+    for line in iter(rc.stdout.readline, b''):
+        if "CLOSED" in line:
+            return False
+        if CRASH_TOKEN in line:
+            return True

I assumed there are only two end cases in lines of stdout, but while we
are trimming the trace input, the crash output (second-to-last line)
may changes, in which case we will go through the output and fail to
find "CLOSED" and CRASH_TOKEN, thus get stuck in the loop above.

To fix this bug and get a more trimmed input trace, we can:

Use the first three words of the second-to-last line instead of the
whole string, which indicate the type of crash as the token.

-        CRASH_TOKEN = output.splitlines()[-2]
+        CRASH_TOKEN = " ".join(outs.splitlines()[-2].split()[0:3])

If we reach the end of a subprocess' output, return False.

+        if line == "":
+            return False

I fix it in [PATCH v7 1/7] and give an example. Could you review again?
Thanks :-)

FYI, I mentioned this situation firstly in [PATCH 1/4], where I gave a
more detailed example:

https://lists.gnu.org/archive/html/qemu-devel/2020-12/msg05888.html

> 
> >      < {trace_path}".format(timeout=TIMEOUT,
> >                             qemu_path=QEMU_PATH,
> >                             qemu_args=QEMU_ARGS,
> >                             trace_path=path),
> >                            shell=True,
> >                            stdin=subprocess.PIPE,
> > -                          stdout=subprocess.PIPE)
> > -    stdo = rc.communicate()[0]
> > -    output = stdo.decode('unicode_escape')
> > -    if rc.returncode == 137:    # Timed Out
> > -        return False
> > -    if len(output.splitlines()) < 2:
> > -        return False
> > -
> > +                          stdout=subprocess.PIPE,
> > +                          encoding="utf-8")
> > +    global CRASH_TOKEN
> >      if CRASH_TOKEN is None:
> > -        CRASH_TOKEN = output.splitlines()[-2]
> > +        try:
> > +            outs, _ = proc.communicate(timeout=5)
> > +            CRASH_TOKEN = outs.splitlines()[-2]
> > +        except subprocess.TimeoutExpired:
> > +            print("subprocess.TimeoutExpired")
> > +            return False
> > +        print("Identifying Crashes by this string:
> > {}".format(CRASH_TOKEN))
> > +        global deduplication_note
> > +        print(deduplication_note)
> > +        return True
> >  
> > -    return CRASH_TOKEN in output
> > +    for line in iter(proc.stdout.readline, b''):
> > +        if "CLOSED" in line:
> > +            return False
> > +        if CRASH_TOKEN in line:
> > +            return True
> > +
> > +    return False
> >  
> >  
> >  def minimize_trace(inpath, outpath):
> > @@ -66,7 +82,6 @@ def minimize_trace(inpath, outpath):
> >      print("Crashed in {} seconds".format(end-start))
> >      TIMEOUT = (end-start)*5
> >      print("Setting the timeout for {} seconds".format(TIMEOUT))
> > -    print("Identifying Crashes by this string:
> > {}".format(CRASH_TOKEN))
> >  
> >      i = 0
> >      newtrace = trace[:]
> > -- 
> > 2.25.1
> >