All of lore.kernel.org
 help / color / mirror / Atom feed
From: Michael Tokarev <mjt@tls.msk.ru>
To: Avi Kivity <avi@redhat.com>
Cc: KVM list <kvm@vger.kernel.org>,
	Jes Sorensen <Jes.Sorensen@redhat.com>,
	linux-perf-users@vger.kernel.org
Subject: Re: high load with usb device
Date: Tue, 14 Sep 2010 14:25:44 +0400	[thread overview]
Message-ID: <4C8F4DA8.50606@msgid.tls.msk.ru> (raw)
In-Reply-To: <4C8F497C.7000904@redhat.com>

14.09.2010 14:07, Avi Kivity пишет:
>  On 09/14/2010 12:00 PM, Michael Tokarev wrote:
>>   # strace -p 23020 -p 23023 -c
>> Process 23020 attached - interrupt to quit
>> Process 23023 attached - interrupt to quit
>> ^CProcess 23020 detached
>> Process 23023 detached
>> % time     seconds  usecs/call     calls    errors syscall
>> ------ ----------- ----------- --------- --------- ----------------
>>   98.98   23.462158       15569      1507           ioctl
>>    0.64    0.151725          37      4063         5 futex
>>    0.11    0.025051           0     86932           select
>>    0.09    0.021188           0    408836           clock_gettime
>>    0.07    0.016543           0    271933    136484 read
>>    0.04    0.008958           0    181118           gettimeofday
>>    0.02    0.005756           0    101190           write
>>    0.02    0.005506           0     89180           timer_settime
>>    0.02    0.004754           0     96271           timer_gettime
>>    0.01    0.002682           0     50595           rt_sigaction
>>    0.00    0.000000           0         1           rt_sigpending
>>    0.00    0.000000           0         1         1 rt_sigtimedwait
>> ------ ----------- ----------- --------- --------- ----------------
>> 100.00   23.704321               1291627    136490 total
>>
>>
> 
> Well, well.  Translating to rates, we have 63.6 ioctls/sec but 17k
> clock_gettime, 11k read() and 4k writes per second.  The device model
> has gone haywire, somehow without any trace in perf top.
> 
> Let's see what those reads and writes are about.  Please strace a short
> segment again, without -c, and use lsof to see which fds are referenced
> in the read and write calls.

Not that it is much helpful either.  lsof:

qemu-syst 23203  mjt    0u   CHR   136,9      0t0      12 /dev/pts/9
qemu-syst 23203  mjt    1u   CHR   136,9      0t0      12 /dev/pts/9
qemu-syst 23203  mjt    2u   CHR   136,9      0t0      12 /dev/pts/9
qemu-syst 23203  mjt    3u   CHR  10,232      0t0    4402 /dev/kvm
qemu-syst 23203  mjt    4u  0000     0,9        0     607 anon_inode
qemu-syst 23203  mjt    5r  FIFO     0,8      0t0 8172675 pipe
qemu-syst 23203  mjt    6w  FIFO     0,8      0t0 8172675 pipe
qemu-syst 23203  mjt    7u   CHR  10,200      0t0    1228 /dev/net/tun
qemu-syst 23203  mjt    8u  0000     0,9        0     607 anon_inode
qemu-syst 23203  mjt    9u  IPv4 8173217      0t0     TCP *:5900 (LISTEN)
qemu-syst 23203  mjt   10u  0000     0,9        0     607 anon_inode
qemu-syst 23203  mjt   11u  0000     0,9        0     607 anon_inode
qemu-syst 23203  mjt   12u  0000     0,9        0     607 anon_inode

(I switched to (unconnected) vnc from sdl to remove X stuff).

Here's the strace (200 lines of it):

23203 14:21:04.417579 select(13, [0 5 7 9 10 12], [], [], {0, 999495} <unfinished ...>
23206 14:21:04.417827 rt_sigtimedwait([BUS RT_6],  <unfinished ...>
23203 14:21:04.417897 <... select resumed> ) = 1 (in [12], left {0, 999476}) <0.000140>
23206 14:21:04.417957 <... rt_sigtimedwait resumed> 0xf6acb124, {0, 0}, 8) = -1 EAGAIN (Resource temporarily unavailable) <0.000070>
23203 14:21:04.418016 read(12,  <unfinished ...>
23206 14:21:04.418063 futex(0x824c444, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
23203 14:21:04.418098 <... read resumed> "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000057>
23203 14:21:04.418213 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000020>
23203 14:21:04.418441 write(6, "\0", 1) = 1 <0.000074>
23203 14:21:04.418787 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000050>
23203 14:21:04.418911 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000021>
23203 14:21:04.419000 clock_gettime(CLOCK_MONOTONIC, {119262, 938833745}) = 0 <0.000019>
23203 14:21:04.419081 gettimeofday({1284459664, 419106}, NULL) = 0 <0.000019>
23203 14:21:04.419158 clock_gettime(CLOCK_MONOTONIC, {119262, 938986680}) = 0 <0.000019>
23203 14:21:04.419232 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000020>
23203 14:21:04.419315 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000023>
23203 14:21:04.419400 clock_gettime(CLOCK_MONOTONIC, {119262, 939228476}) = 0 <0.000018>
23203 14:21:04.419477 clock_gettime(CLOCK_MONOTONIC, {119262, 939305118}) = 0 <0.000018>
23203 14:21:04.419550 clock_gettime(CLOCK_MONOTONIC, {119262, 939378782}) = 0 <0.000019>
23203 14:21:04.419629 gettimeofday({1284459664, 419652}, NULL) = 0 <0.000019>
23203 14:21:04.419704 clock_gettime(CLOCK_MONOTONIC, {119262, 939532390}) = 0 <0.000018>
23203 14:21:04.419777 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000019>
23203 14:21:04.419857 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 927000}}, NULL) = 0 <0.000020>
23203 14:21:04.419936 clock_gettime(CLOCK_MONOTONIC, {119262, 939763985}) = 0 <0.000018>
23203 14:21:04.420008 gettimeofday({1284459664, 420031}, NULL) = 0 <0.000019>
23203 14:21:04.420089 futex(0x824c444, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
23206 14:21:04.420143 <... futex resumed> ) = 0 <0.002052>
23203 14:21:04.420174 <... futex resumed> ) = 1 <0.000064>
23206 14:21:04.420217 rt_sigpending( <unfinished ...>
23203 14:21:04.420249 select(13, [0 5 7 9 10 12], [], [], {1, 0} <unfinished ...>
23206 14:21:04.420294 <... rt_sigpending resumed> [ALRM]) = 0 <0.000059>
23203 14:21:04.420343 <... select resumed> ) = 3 (in [5 10 12], left {0, 999984}) <0.000055>
23206 14:21:04.420393 futex(0x824c444, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
23203 14:21:04.420424 read(12,  <unfinished ...>
23206 14:21:04.420452 <... futex resumed> ) = 0 <0.000037>
23203 14:21:04.420479 <... read resumed> "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000036>
23206 14:21:04.420543 ioctl(8, KVM_RUN <unfinished ...>
23203 14:21:04.420592 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000024>
23203 14:21:04.420739 write(6, "\0", 1) = 1 <0.000027>
23203 14:21:04.420828 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000018>
23203 14:21:04.420910 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000021>
23203 14:21:04.421039 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000020>
23203 14:21:04.421181 write(6, "\0", 1) = 1 <0.000025>
23203 14:21:04.421264 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000052>
23203 14:21:04.421379 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000020>
23203 14:21:04.421457 read(10, "\3\0\0\0\0\0\0\0", 4096) = 8 <0.000019>
23203 14:21:04.421538 read(10, 0xffa86510, 4096) = -1 EAGAIN (Resource temporarily unavailable) <0.000019>
23203 14:21:04.421632 read(5, "\0\0\0", 512) = 3 <0.000047>
23203 14:21:04.421742 read(5, 0xffa87310, 512) = -1 EAGAIN (Resource temporarily unavailable) <0.000052>
23203 14:21:04.421864 clock_gettime(CLOCK_MONOTONIC, {119262, 941710424}) = 0 <0.000037>
23203 14:21:04.421959 gettimeofday({1284459664, 421983}, NULL) = 0 <0.000019>
23203 14:21:04.422034 clock_gettime(CLOCK_MONOTONIC, {119262, 941862127}) = 0 <0.000018>
23203 14:21:04.422108 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000020>
23203 14:21:04.422189 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000099>
23203 14:21:04.422413 clock_gettime(CLOCK_MONOTONIC, {119262, 942253027}) = 0 <0.000022>
23203 14:21:04.422512 clock_gettime(CLOCK_MONOTONIC, {119262, 942342550}) = 0 <0.000019>
23203 14:21:04.422589 clock_gettime(CLOCK_MONOTONIC, {119262, 942418192}) = 0 <0.000018>
23203 14:21:04.422663 gettimeofday({1284459664, 422686}, NULL) = 0 <0.000018>
23203 14:21:04.422737 clock_gettime(CLOCK_MONOTONIC, {119262, 942565097}) = 0 <0.000018>
23203 14:21:04.422809 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000019>
23203 14:21:04.422890 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 925000}}, NULL) = 0 <0.000087>
23203 14:21:04.423100 clock_gettime(CLOCK_MONOTONIC, {119262, 942938261}) = 0 <0.000021>
23203 14:21:04.423188 gettimeofday({1284459664, 423212}, NULL) = 0 <0.000020>
23203 14:21:04.423273 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999982}) <0.000089>
23203 14:21:04.423517 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000026>
23203 14:21:04.423673 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000020>
23203 14:21:04.423861 write(6, "\0", 1) = 1 <0.000050>
23203 14:21:04.424008 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000054>
23203 14:21:04.424127 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000022>
23203 14:21:04.424311 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000058>
23203 14:21:04.424521 write(6, "\0", 1) = 1 <0.000027>
23203 14:21:04.424607 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000020>
23203 14:21:04.424691 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000021>
23203 14:21:04.424771 clock_gettime(CLOCK_MONOTONIC, {119262, 944601250}) = 0 <0.000020>
23203 14:21:04.424848 gettimeofday({1284459664, 424872}, NULL) = 0 <0.000019>
23203 14:21:04.424923 clock_gettime(CLOCK_MONOTONIC, {119262, 944805889}) = 0 <0.000048>
23203 14:21:04.425068 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000021>
23203 14:21:04.425152 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000075>
23203 14:21:04.425292 clock_gettime(CLOCK_MONOTONIC, {119262, 945121851}) = 0 <0.000020>
23203 14:21:04.425372 clock_gettime(CLOCK_MONOTONIC, {119262, 945200578}) = 0 <0.000019>
23203 14:21:04.425446 clock_gettime(CLOCK_MONOTONIC, {119262, 945278488}) = 0 <0.000021>
23203 14:21:04.425524 gettimeofday({1284459664, 425548}, NULL) = 0 <0.000020>
23203 14:21:04.425600 clock_gettime(CLOCK_MONOTONIC, {119262, 945428567}) = 0 <0.000019>
23203 14:21:04.425674 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000019>
23203 14:21:04.425754 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 923000}}, NULL) = 0 <0.000019>
23203 14:21:04.425835 clock_gettime(CLOCK_MONOTONIC, {119262, 945663413}) = 0 <0.000019>
23203 14:21:04.425909 gettimeofday({1284459664, 425932}, NULL) = 0 <0.000018>
23203 14:21:04.425991 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 3 (in [5 10 12], left {0, 999983}) <0.000091>
23203 14:21:04.426232 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000025>
23203 14:21:04.426388 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000019>
23203 14:21:04.426535 write(6, "\0", 1) = 1 <0.000027>
23203 14:21:04.426621 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000055>
23203 14:21:04.426744 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000022>
23203 14:21:04.426946 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000057>
23203 14:21:04.427155 write(6, "\0", 1) = 1 <0.000026>
23203 14:21:04.427240 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000019>
23203 14:21:04.427322 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000020>
23203 14:21:04.427400 read(10, "\4\0\0\0\0\0\0\0", 4096) = 8 <0.000019>
23203 14:21:04.427481 read(10, 0xffa86510, 4096) = -1 EAGAIN (Resource temporarily unavailable) <0.000018>
23203 14:21:04.427555 read(5, "\0\0\0\0", 512) = 4 <0.000022>
23203 14:21:04.427635 read(5, 0xffa87310, 512) = -1 EAGAIN (Resource temporarily unavailable) <0.000019>
23203 14:21:04.427709 clock_gettime(CLOCK_MONOTONIC, {119262, 947539408}) = 0 <0.000020>
23203 14:21:04.429301 gettimeofday({1284459664, 429383}, NULL) = 0 <0.000018>
23203 14:21:04.429442 clock_gettime(CLOCK_MONOTONIC, {119262, 949275654}) = 0 <0.000014>
23203 14:21:04.429518 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000015>
23203 14:21:04.429598 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000017>
23203 14:21:04.429676 clock_gettime(CLOCK_MONOTONIC, {119262, 949504996}) = 0 <0.000013>
23203 14:21:04.429750 clock_gettime(CLOCK_MONOTONIC, {119262, 949579332}) = 0 <0.000014>
23203 14:21:04.429819 clock_gettime(CLOCK_MONOTONIC, {119262, 949647805}) = 0 <0.000013>
23203 14:21:04.429891 gettimeofday({1284459664, 429914}, NULL) = 0 <0.000013>
23203 14:21:04.429959 clock_gettime(CLOCK_MONOTONIC, {119262, 949787250}) = 0 <0.000014>
23203 14:21:04.430025 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000013>
23203 14:21:04.430098 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 932000}}, NULL) = 0 <0.000015>
23203 14:21:04.430173 clock_gettime(CLOCK_MONOTONIC, {119262, 950001657}) = 0 <0.000013>
23203 14:21:04.430240 gettimeofday({1284459664, 430263}, NULL) = 0 <0.000013>
23203 14:21:04.430319 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999988}) <0.000028>
23203 14:21:04.430438 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000015>
23203 14:21:04.430546 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000014>
23203 14:21:04.430658 write(6, "\0", 1) = 1 <0.000017>
23203 14:21:04.430733 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000015>
23203 14:21:04.430810 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
23203 14:21:04.430883 clock_gettime(CLOCK_MONOTONIC, {119262, 950713026}) = 0 <0.000013>
23203 14:21:04.430952 gettimeofday({1284459664, 430975}, NULL) = 0 <0.000013>
23203 14:21:04.431020 clock_gettime(CLOCK_MONOTONIC, {119262, 950848643}) = 0 <0.000013>
23203 14:21:04.431091 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000014>
23203 14:21:04.431165 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000015>
23203 14:21:04.431241 clock_gettime(CLOCK_MONOTONIC, {119262, 951070442}) = 0 <0.000014>
23203 14:21:04.431312 clock_gettime(CLOCK_MONOTONIC, {119262, 951141565}) = 0 <0.000014>
23203 14:21:04.431381 clock_gettime(CLOCK_MONOTONIC, {119262, 951209628}) = 0 <0.000014>
23203 14:21:04.431448 gettimeofday({1284459664, 431474}, NULL) = 0 <0.000014>
23203 14:21:04.431519 clock_gettime(CLOCK_MONOTONIC, {119262, 951347952}) = 0 <0.000013>
23203 14:21:04.431586 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000014>
23203 14:21:04.431662 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 932000}}, NULL) = 0 <0.000016>
23203 14:21:04.431740 clock_gettime(CLOCK_MONOTONIC, {119262, 951569525}) = 0 <0.000014>
23203 14:21:04.431809 gettimeofday({1284459664, 431833}, NULL) = 0 <0.000013>
23203 14:21:04.431897 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 3 (in [5 10 12], left {0, 999993}) <0.000021>
23203 14:21:04.432005 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000015>
23203 14:21:04.432125 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000014>
23203 14:21:04.432233 write(6, "\0", 1) = 1 <0.000017>
23203 14:21:04.432305 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000014>
23203 14:21:04.432378 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000012>
23203 14:21:04.432444 read(10, "\2\0\0\0\0\0\0\0", 4096) = 8 <0.000013>
23203 14:21:04.432518 read(10, 0xffa86510, 4096) = -1 EAGAIN (Resource temporarily unavailable) <0.000013>
23203 14:21:04.432584 read(5, "\0\0", 512) = 2 <0.000014>
23203 14:21:04.432658 read(5, 0xffa87310, 512) = -1 EAGAIN (Resource temporarily unavailable) <0.000012>
23203 14:21:04.432724 clock_gettime(CLOCK_MONOTONIC, {119262, 952551357}) = 0 <0.000012>
23203 14:21:04.432789 gettimeofday({1284459664, 432811}, NULL) = 0 <0.000012>
23203 14:21:04.432854 clock_gettime(CLOCK_MONOTONIC, {119262, 952681486}) = 0 <0.000012>
23203 14:21:04.432919 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000013>
23203 14:21:04.432990 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000014>
23203 14:21:04.433062 clock_gettime(CLOCK_MONOTONIC, {119262, 952889944}) = 0 <0.000012>
23203 14:21:04.433129 clock_gettime(CLOCK_MONOTONIC, {119262, 952957001}) = 0 <0.000012>
23203 14:21:04.433194 clock_gettime(CLOCK_MONOTONIC, {119262, 953021746}) = 0 <0.000012>
23203 14:21:04.433259 gettimeofday({1284459664, 433283}, NULL) = 0 <0.000012>
23203 14:21:04.433327 clock_gettime(CLOCK_MONOTONIC, {119262, 953154033}) = 0 <0.000013>
23203 14:21:04.433392 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000013>
23203 14:21:04.433463 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 936000}}, NULL) = 0 <0.000014>
23203 14:21:04.433535 clock_gettime(CLOCK_MONOTONIC, {119262, 953363023}) = 0 <0.000013>
23203 14:21:04.433601 gettimeofday({1284459664, 433622}, NULL) = 0 <0.000012>
23203 14:21:04.433670 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999992}) <0.000021>
23203 14:21:04.433771 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000013>
23203 14:21:04.433887 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000022>
23203 14:21:04.434089 write(6, "\0", 1) = 1 <0.000064>
23203 14:21:04.434247 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000052>
23203 14:21:04.434367 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000021>
23203 14:21:04.434456 clock_gettime(CLOCK_MONOTONIC, {119262, 954287414}) = 0 <0.000020>
23203 14:21:04.434535 gettimeofday({1284459664, 434559}, NULL) = 0 <0.000019>
23203 14:21:04.434610 clock_gettime(CLOCK_MONOTONIC, {119262, 954438671}) = 0 <0.000019>
23203 14:21:04.434684 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000020>
23203 14:21:04.434766 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000023>
23203 14:21:04.434849 clock_gettime(CLOCK_MONOTONIC, {119262, 954678059}) = 0 <0.000018>
23203 14:21:04.434929 clock_gettime(CLOCK_MONOTONIC, {119262, 954778987}) = 0 <0.000040>
23203 14:21:04.435027 clock_gettime(CLOCK_MONOTONIC, {119262, 954856108}) = 0 <0.000019>
23203 14:21:04.435101 gettimeofday({1284459664, 435125}, NULL) = 0 <0.000019>
23203 14:21:04.435176 clock_gettime(CLOCK_MONOTONIC, {119262, 955004347}) = 0 <0.000018>
23203 14:21:04.435276 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000019>
23203 14:21:04.435357 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 923000}}, NULL) = 0 <0.000020>
23203 14:21:04.435437 clock_gettime(CLOCK_MONOTONIC, {119262, 955265191}) = 0 <0.000018>
23203 14:21:04.435510 gettimeofday({1284459664, 435533}, NULL) = 0 <0.000018>
23203 14:21:04.435594 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 3 (in [5 10 12], left {0, 999983}) <0.000096>
23203 14:21:04.435840 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000026>
23203 14:21:04.436037 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000054>
23203 14:21:04.436260 write(6, "\0", 1) = 1 <0.000028>
23203 14:21:04.436356 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000054>
23203 14:21:04.436475 read(12, "\16\0\0\0\0\0\0\0\376\377\377\377\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\0\0"..., 128) = 128 <0.000022>
23203 14:21:04.436661 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL STOP RTMIN RT_1], 0}, 8) = 0 <0.000062>
23203 14:21:04.436874 write(6, "\0", 1) = 1 <0.000027>
23203 14:21:04.436960 write(11, "\1\0\0\0\0\0\0\0", 8) = 8 <0.000021>
23203 14:21:04.437045 read(12, 0xffa87480, 128) = -1 EAGAIN (Resource temporarily unavailable) <0.000021>
23203 14:21:04.437123 read(10, "\3\0\0\0\0\0\0\0", 4096) = 8 <0.000020>
23203 14:21:04.437205 read(10, 0xffa86510, 4096) = -1 EAGAIN (Resource temporarily unavailable) <0.000018>
23203 14:21:04.437279 read(5, "\0\0\0", 512) = 3 <0.000023>
23203 14:21:04.437360 read(5, 0xffa87310, 512) = -1 EAGAIN (Resource temporarily unavailable) <0.000019>
23203 14:21:04.437434 clock_gettime(CLOCK_MONOTONIC, {119262, 957264356}) = 0 <0.000020>
23203 14:21:04.437511 gettimeofday({1284459664, 437535}, NULL) = 0 <0.000019>
23203 14:21:04.437586 clock_gettime(CLOCK_MONOTONIC, {119262, 957414785}) = 0 <0.000019>
23203 14:21:04.437660 timer_gettime(0x1, {it_interval={0, 0}, it_value={0, 0}}) = 0 <0.000020>
23203 14:21:04.437743 timer_settime(0x1, 0, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0 <0.000091>
23203 14:21:04.437958 clock_gettime(CLOCK_MONOTONIC, {119262, 957798172}) = 0 <0.000022>
23203 14:21:04.438054 clock_gettime(CLOCK_MONOTONIC, {119262, 957882793}) = 0 <0.000025>

So it is constantly poking fds# 11, 12, 10, 5 & 6.
5 and 6 are pipe (selfpipe?), and 10..12 are "anon inode".

Here's the command line again:

qemu-system-x86_64 \
  -netdev type=tap,ifname=tap-kvm,id=x \
  -device virtio-net-pci,netdev=x \
  -monitor stdio \
  -boot n \
  -usbdevice tablet \
  -m 1G \
  -vnc :0

Yes, it does quite a lot of timer stuff... ;)

Thanks!

/mjt

  reply	other threads:[~2010-09-14 10:25 UTC|newest]

Thread overview: 36+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2010-09-03 12:21 high load with win7 & usb tablet Michael Tokarev
2010-09-10 11:47 ` Jes Sorensen
2010-09-10 12:16   ` Michael Tokarev
2010-09-10 16:17     ` high load with usb device Michael Tokarev
2010-09-12  9:26       ` Avi Kivity
2010-09-14  6:51         ` Michael Tokarev
2010-09-14  9:06           ` Avi Kivity
2010-09-14  9:08             ` Avi Kivity
2010-09-14 10:00               ` Michael Tokarev
2010-09-14 10:07                 ` Avi Kivity
2010-09-14 10:25                   ` Michael Tokarev [this message]
2010-09-14 10:39                     ` Avi Kivity
2010-09-14 11:02                       ` Michael Tokarev
2010-09-14 13:15                         ` Michael Tokarev
2010-09-14 13:25                           ` Avi Kivity
2010-09-14 13:29                             ` Michael Tokarev
2010-09-14 13:38                               ` Michael Tokarev
2010-09-14 14:45                               ` Avi Kivity
2010-09-14 14:53                                 ` Michael Tokarev
2010-09-14 16:00                                   ` Avi Kivity
2010-09-14 16:29                                     ` Michael Tokarev
2010-09-14 16:37                                       ` Avi Kivity
2010-09-14 16:50                                         ` Michael Tokarev
2010-09-14 16:45                                       ` David S. Ahern
2010-09-14 15:51                                 ` David S. Ahern
2010-09-14 16:00                                   ` Michael Tokarev
2010-09-14 16:09                                     ` David S. Ahern
2010-09-10 12:19 ` high load with win7 & usb tablet Avi Kivity
2010-09-10 12:44   ` Michael Tokarev
2010-09-10 12:50     ` Avi Kivity
     [not found]       ` <4C8A44E6.2060008@msgid.tls.msk.ru>
2010-09-10 14:56         ` Avi Kivity
2010-09-10 15:03           ` Michael Tokarev
2010-09-10 16:03             ` Avi Kivity
2010-09-14  8:26               ` Brad Campbell
2010-09-14  8:33                 ` Michael Tokarev
2010-09-14  8:46                   ` Brad Campbell

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=4C8F4DA8.50606@msgid.tls.msk.ru \
    --to=mjt@tls.msk.ru \
    --cc=Jes.Sorensen@redhat.com \
    --cc=avi@redhat.com \
    --cc=kvm@vger.kernel.org \
    --cc=linux-perf-users@vger.kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.