Re: [RESEND PATCH 0/5] perf core: Support overwrite ring buffer
From: Ingo Molnar
Date: Tue Mar 08 2016 - 12:24:40 EST
* 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:
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