Re: perf trace errors

Ingo Molnar
2009-10-16T08:33:31Z

* Christoph Hellwig <hch@lst.de> wrote:

> I get some rather interesting errors using perf trace with the block
> tracepoints on current mainline, e.g.:
>
> perf record -f -e 'block:block_bio_queue:record' -R -F 1 -a -s
> <do some disk I/O end then ctrl+c>
> ^C[ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.237 MB perf.data (~10362 samples) ]
>
> brick:/home/hch# perf trace
> Fatal: unknown op '-'
> xfssyncd-4232 [000] 87.798249255: block_bio_queue: 253,
>
> There are lots of occurances of that exactly same warning in
> builtin-trace.c, and the code sourrouning them is sufficiently enough
> convoluted that I'm not able to track it down.

FYI, these bugs are fixed in latest -tip, your testcase works for me:

aldebaran:~/linux/linux/tools/perf> perf record -f -e 'block:block_bio_queue:record' -R -F 1 -a -s
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.027 MB perf.data (~1168 samples) ]

aldebaran:~/linux/linux/tools/perf> perf trace
kjournald-1406 [000] 10900.853086: block_bio_queue: 8,0 W 68735 + 8 [kjournald]
kjournald-1406 [000] 10900.853097: block_bio_queue: 8,0 W 68743 + 8 [kjournald]
kjournald-1406 [000] 10900.853100: block_bio_queue: 8,0 W 68751 + 8 [kjournald]
kjournald-1406 [000] 10900.853103: block_bio_queue: 8,0 W 68759 + 8 [kjournald]
flush-8:0-20110 [007] 10900.853117: block_bio_queue: 8,0 W 64487535 + 8 [flush-8:0]
flush-8:0-20110 [007] 10900.853129: block_bio_queue: 8,0 W 64487551 + 8 [flush-8:0]
flush-8:0-20110 [007] 10900.853138: block_bio_queue: 8,0 W 64487559 + 8 [flush-8:0]
flush-8:0-20110 [007] 10900.853149: block_bio_queue: 8,0 W 64700511 + 8 [flush-8:0]
sync-16876 [008] 10900.851948: block_bio_queue: 8,0 R 3218919 + 40 [sync]
sync-16876 [008] 10900.853062: block_bio_queue: 8,0 W 63 + 8 [sync]
sync-16876 [008] 10900.853067: block_bio_queue: 8,0 W 71 + 8 [sync]
sync-16876 [008] 10900.853071: block_bio_queue: 8,0 W 79 + 8 [sync]
sync-16876 [008] 10900.853077: block_bio_queue: 8,0 W 15466559 + 8 [sync]
sync-16876 [011] 10900.840473: block_bio_queue: 8,0 R 3218887 + 32 [bash]

Mind checking whether it works for you?

Thanks,

Ingo