lkml.org 
[lkml]   [2012]   [Sep]   [14]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
Subjectperf script: rwtop: SIGALRM and pipe read race

I recently tried 'perf script rwtop', and it immediately failed with
'failed to read event header'. Running it through strace I found that the
when rwtop.pl is reading from the pipe, and gets one of it's alarms, that
the ERESTARTSYS seems to confuse it - causing it to fail. It also appears
that the problem only happens early in execution, or not at all. If I get
lucky and don't hit the problem right away, then rwtop will run fine as
long as I want, without any ERESTARTSYS's in its trace. I also found that
I can avoid hitting the problem by throwing a 'pv -q' in front of the perf
command in tools/perf/scripts/perl/bin/rwtop-report. Which I guess slows
things down in the reader enough to always avoid the race.

Sorry I don't have a solution (patch). I'll look at it more as time
permits, but I thought I'd get it reported for starters though.

Drew

Partial strace below

16774 read(0, <unfinished ...>
16772 <... getdents resumed> /* 0 entries */, 32768) = 0
16774 <... read resumed>
"\206A\0\0\206A\0\0perf\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 48) =
48
16772 close(70 <unfinished ...>
16774 read(0, <unfinished ...>
16772 <... close resumed> ) = 0
16772 open("/proc/16774/maps", O_RDONLY) = 70
16772 fstat(70, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
16772 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS,
-1, 0) = 0x7f76c6b5b000
16772 read(70, "00400000-00582000 r-xp 00000000 "..., 1024) = 1024
16774 <... read resumed> 0x28598e0, 8) = ? ERESTARTSYS (To be restarted
if SA_RESTART is set)
16772 write(1, "\1\0\0\0\2\0p\0\206A\0\0\206A\0\0\0\0@\0\0\0\0\0\0
\30\0\0\0\0\0"..., 112 <unfinished ...>
16774 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
16772 <... write resumed> ) = 112
16774 rt_sigreturn( <unfinished ...>
16772 write(1,
"\1\0\0\0\2\0`\0\206A\0\0\206A\0\0\0\0\240\0072\0\0\0\0\0\2\0\0\0\0\0"...,
96 <unfinished ...>
16774 <... rt_sigreturn resumed> ) = -1 EINTR (Interrupted system
call)
16772 <... write resumed> ) = 96
16774 write(2, "failed to read event header\n", 28 <unfinished ...>


\
 
 \ /
  Last update: 2012-09-14 18:21    [W:2.124 / U:0.100 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site