Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S932195AbcCHRYi (ORCPT <rfc822;w@1wt.eu>);
	Tue, 8 Mar 2016 12:24:38 -0500
Received: from mail-wm0-f65.google.com ([74.125.82.65]:35445 "EHLO
	mail-wm0-f65.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1751601AbcCHRYb (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Tue, 8 Mar 2016 12:24:31 -0500
Date: Tue, 8 Mar 2016 18:24:25 +0100
From: Ingo Molnar <mingo@kernel.org>
To: Dmitry Vyukov <dvyukov@google.com>
Cc: Peter Zijlstra <peterz@infradead.org>, Wang Nan <wangnan0@huawei.com>,
        Ingo Molnar <mingo@redhat.com>, LKML <linux-kernel@vger.kernel.org>,
        He Kuang <hekuang@huawei.com>, Alexei Starovoitov <ast@kernel.org>,
        Arnaldo Carvalho de Melo <acme@redhat.com>,
        Brendan Gregg <brendan.d.gregg@gmail.com>,
        Jiri Olsa <jolsa@kernel.org>,
        Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>,
        Namhyung Kim <namhyung@kernel.org>, Zefan Li <lizefan@huawei.com>,
        pi3orama@163.com
Subject: Re: [RESEND PATCH 0/5] perf core: Support overwrite ring buffer
Message-ID: <20160308172425.GA3017@gmail.com>
References: <20160308135759.GH6356@twins.programming.kicks-ass.net>
 <20160308152924.GB9147@gmail.com>
 <CACT4Y+Y6+S9E+vJUZzWxyU+0M5i3L_+8knhxFtfaWYkdN5Vusg@mail.gmail.com>
 <20160308155423.GA16587@gmail.com>
 <CACT4Y+YwsGU1t62o20GTNQZ1=uQW1CateC+gSRFMG7Pmxi+WQw@mail.gmail.com>
 <20160308162703.GB30211@gmail.com>
 <CACT4Y+aTmdQfeBcQ=8dt=XV7MBHP-+kDLbXAZ_cJ93npGrih1g@mail.gmail.com>
 <20160308164438.GA24109@gmail.com>
 <20160308164859.GA27516@gmail.com>
 <CACT4Y+amJpRg9jdz1vEupJO8gsbeh7PuOKTiuvkuu7cWigY50Q@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <CACT4Y+amJpRg9jdz1vEupJO8gsbeh7PuOKTiuvkuu7cWigY50Q@mail.gmail.com>
User-Agent: Mutt/1.5.23 (2014-03-12)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 6383
Lines: 105


* Dmitry Vyukov <dvyukov@google.com> wrote:

> On Tue, Mar 8, 2016 at 5:48 PM, Ingo Molnar <mingo@kernel.org> wrote:
> >
> > * Ingo Molnar <mingo@kernel.org> wrote:
> >
> >> It only had a couple of seconds of runtime:
> >>
> >>  49652 mingo     20   0 1434276  52144  11344 S   0.0  0.0   0:00.54 syz-manager
> >>  49661 mingo     20   0 2196672  43948  10448 S   0.0  0.0   0:05.59 syz-fuzzer
> >
> > Ah, so it appears to making some progress:
> >
> >  49652 mingo     20   0 1581740  47600  11344 S   0.0  0.0   0:00.58 syz-manager
> >  49661 mingo     20   0 2204868  43720  10448 S   0.0  0.0   0:07.49 syz-fuzzer
> >
> >  49652 mingo     20   0 1598132  31512  11344 S   0.0  0.0   0:00.61 syz-manager
> >  49661 mingo     20   0 2204868  44252  10448 S   0.0  0.0   0:09.09 syz-fuzzer
> >
> > but only about +1 second runtime added every minute or so. Is that expected?
> 
> The main work is done by child syz-executor processes.

Hm, they don't seem to be doing anything:

fomalhaut:~> ps aux | grep syz-executor
mingo     41506  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41509  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41513  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41515  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41523  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41601  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41608  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41662  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41764  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     41966  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42029  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42084  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42145  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42149  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42166  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     42175  0.0  0.0      0     0 pts/2    Z+   18:19   0:00 [syz-executor] <defunct>
mingo     57627  2.2  0.0 1860540 44884 pts/2   Sl+  18:16   0:04 /home/mingo/go/src/github.com/google/syzkaller/workdir/instance-0/syz-fuzzer -executor /home/mingo/go/src/github.com/google/syzkaller/workdir/instance-0/syz-executor -name local-0 -manager 127.0.0.1:33809 -output=none -procs 16 -leak=false -cover=false -nobody=true -v 0

... because they are recycling:

fomalhaut:~> ps aux | grep syz-executor
mingo     57627  1.6  0.0 1942468 44624 pts/2   Sl+  18:16   0:05 /home/mingo/go/src/github.com/google/syzkaller/workdir/instance-0/syz-fuzzer -executor /home/mingo/go/src/github.com/google/syzkaller/workdir/instance-0/syz-executor -name local-0 -manager 127.0.0.1:33809 -output=none -procs 16 -leak=false -cover=false -nobody=true -v 0
mingo     98448  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98454  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98468  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98472  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98476  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98522  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98525  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98548  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98568  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98596  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98618  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98644  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98695  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98708  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98737  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>
mingo     98756  0.0  0.0      0     0 pts/2    Z+   18:21   0:00 [syz-executor] <defunct>

I'm not seeing anything happen in 'top' - only a mostly idle system.

> syz-manager/syz-fuzzer only guide the process.
> You can set "procs" param in config to higher value to increase CPU
> utilization. To get more bugs you want to saturate all CPUs to trigger
> more unusual thread interleavings.

So right now it doesn't seem to saturate 16 CPUs - not even close to it.

> If there is a second unfinished thread hanging on a kernel spinlock or
> mutex, then it's definitely bad.
> It also helps to enable CONFIG_RCU_STALL_COMMON=y,
> CONFIG_DEBUG_ATOMIC_SLEEP=y, CONFIG_WQ_WATCHDOG=y and spinlock/mutex
> debugging. These can detect various stalls.

I can just Ctrl-C the manager and it shuts down within a few seconds:

2016/03/08 17:39:25 serving rpc on tcp://127.0.0.1:33809
2016/03/08 17:51:45 local-0: lost connection: exit status 2
2016/03/08 17:51:45 local-0: saving crash 'lost connection' to crash-local-0-1457455905403390570
2016/03/08 18:04:04 local-0: lost connection: exit status 2
2016/03/08 18:04:04 local-0: saving crash 'lost connection' to crash-local-0-1457456644779165131
2016/03/08 18:16:24 local-0: lost connection: exit status 2
2016/03/08 18:16:24 local-0: saving crash 'lost connection' to crash-local-0-1457457384707190124
^C2016/03/08 18:22:53 shutting down...

with nothing hanging around:

fomalhaut:~/go/src/github.com/google/syzkaller> ps aux | grep -i syz
mingo      1374  0.0  0.0 118476  2376 pts/2    S+   18:23   0:00 grep --color=auto -i syz

and with no kernel messages in dmesg - and with a fully functional system.

I'm running the 16-task load on a 120 CPU system - should I increase it to 120? 
Does the code expect to saturate the system?

Thanks,

	Ingo