Re: [RESEND PATCH 0/5] perf core: Support overwrite ring buffer

From: Dmitry Vyukov
Date: Tue Mar 08 2016 - 12:27:52 EST

On Tue, Mar 8, 2016 at 6:24 PM, Ingo Molnar <mingo@xxxxxxxxxx> wrote:
>
> * Dmitry Vyukov <dvyukov@xxxxxxxxxx> wrote:
>
>> On Tue, Mar 8, 2016 at 5:48 PM, Ingo Molnar <mingo@xxxxxxxxxx> wrote:
>> >
>> > * Ingo Molnar <mingo@xxxxxxxxxx> 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.