Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S932501AbcCHR1t (ORCPT <rfc822;w@1wt.eu>);
	Tue, 8 Mar 2016 12:27:49 -0500
Received: from mail-wm0-f52.google.com ([74.125.82.52]:36258 "EHLO
	mail-wm0-f52.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1751601AbcCHR1n convert rfc822-to-8bit (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Tue, 8 Mar 2016 12:27:43 -0500
MIME-Version: 1.0
In-Reply-To: <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> <20160308172425.GA3017@gmail.com>
From: Dmitry Vyukov <dvyukov@google.com>
Date: Tue, 8 Mar 2016 18:27:21 +0100
Message-ID: <CACT4Y+ZbJk6smr11ctniFW577_BKcjHJd1duyA4h7taPmAPP=A@mail.gmail.com>
Subject: Re: [RESEND PATCH 0/5] perf core: Support overwrite ring buffer
To: Ingo Molnar <mingo@kernel.org>
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
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8BIT
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 6709
Lines: 107

On Tue, Mar 8, 2016 at 6:24 PM, Ingo Molnar <mingo@kernel.org> wrote:
>
> * 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:

OK, this all looks good.

> 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?

No, it does not expect to saturate the system. Set "procs" to 480, or
something like that.