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
next prev parent 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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox