From mboxrd@z Thu Jan 1 00:00:00 1970 From: Michael Tokarev Subject: Re: high load with usb device Date: Tue, 14 Sep 2010 14:25:44 +0400 Message-ID: <4C8F4DA8.50606@msgid.tls.msk.ru> References: <4C80E839.50604@msgid.tls.msk.ru> <4C8A1AE3.8030705@redhat.com> <4C8A2187.1020202@msgid.tls.msk.ru> <4C8A59FE.9090400@msgid.tls.msk.ru> <4C8C9CAA.9030203@redhat.com> <4C8F1B54.60604@msgid.tls.msk.ru> <4C8F3B00.3000703@redhat.com> <4C8F3BA7.7060302@redhat.com> <4C8F47A1.4030600@msgid.tls.msk.ru> <4C8F497C.7000904@redhat.com> Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: QUOTED-PRINTABLE Cc: KVM list , Jes Sorensen , linux-perf-users@vger.kernel.org To: Avi Kivity Return-path: Received: from isrv.corpit.ru ([86.62.121.231]:52355 "EHLO isrv.corpit.ru" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753426Ab0INKZr (ORCPT ); Tue, 14 Sep 2010 06:25:47 -0400 In-Reply-To: <4C8F497C.7000904@redhat.com> Sender: kvm-owner@vger.kernel.org List-ID: 14.09.2010 14:07, Avi Kivity =D0=BF=D0=B8=D1=88=D0=B5=D1=82: > 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 >> >> >=20 > 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. >=20 > Let's see what those reads and writes are about. Please strace a sho= rt > segment again, without -c, and use lsof to see which fds are referenc= ed > 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 (LISTE= N) 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], 23203 14:21:04.417897 <... select resumed> ) =3D 1 (in [12], left {0, 9= 99476}) <0.000140> 23206 14:21:04.417957 <... rt_sigtimedwait resumed> 0xf6acb124, {0, 0},= 8) =3D -1 EAGAIN (Resource temporarily unavailable) <0.000070> 23203 14:21:04.418016 read(12, 23206 14:21:04.418063 futex(0x824c444, FUTEX_WAIT_PRIVATE, 2, NULL 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) =3D 128 <0.00005= 7> 23203 14:21:04.418213 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000020> 23203 14:21:04.418441 write(6, "\0", 1) =3D 1 <0.000074> 23203 14:21:04.418787 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000050> 23203 14:21:04.418911 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000021> 23203 14:21:04.419000 clock_gettime(CLOCK_MONOTONIC, {119262, 938833745= }) =3D 0 <0.000019> 23203 14:21:04.419081 gettimeofday({1284459664, 419106}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.419158 clock_gettime(CLOCK_MONOTONIC, {119262, 938986680= }) =3D 0 <0.000019> 23203 14:21:04.419232 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000020> 23203 14:21:04.419315 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000023> 23203 14:21:04.419400 clock_gettime(CLOCK_MONOTONIC, {119262, 939228476= }) =3D 0 <0.000018> 23203 14:21:04.419477 clock_gettime(CLOCK_MONOTONIC, {119262, 939305118= }) =3D 0 <0.000018> 23203 14:21:04.419550 clock_gettime(CLOCK_MONOTONIC, {119262, 939378782= }) =3D 0 <0.000019> 23203 14:21:04.419629 gettimeofday({1284459664, 419652}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.419704 clock_gettime(CLOCK_MONOTONIC, {119262, 939532390= }) =3D 0 <0.000018> 23203 14:21:04.419777 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000019> 23203 14:21:04.419857 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 927000}}, NULL) =3D 0 <0.000020> 23203 14:21:04.419936 clock_gettime(CLOCK_MONOTONIC, {119262, 939763985= }) =3D 0 <0.000018> 23203 14:21:04.420008 gettimeofday({1284459664, 420031}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.420089 futex(0x824c444, FUTEX_WAKE_PRIVATE, 1 23206 14:21:04.420143 <... futex resumed> ) =3D 0 <0.002052> 23203 14:21:04.420174 <... futex resumed> ) =3D 1 <0.000064> 23206 14:21:04.420217 rt_sigpending( 23203 14:21:04.420249 select(13, [0 5 7 9 10 12], [], [], {1, 0} 23206 14:21:04.420294 <... rt_sigpending resumed> [ALRM]) =3D 0 <0.0000= 59> 23203 14:21:04.420343 <... select resumed> ) =3D 3 (in [5 10 12], left = {0, 999984}) <0.000055> 23206 14:21:04.420393 futex(0x824c444, FUTEX_WAKE_PRIVATE, 1 23203 14:21:04.420424 read(12, 23206 14:21:04.420452 <... futex resumed> ) =3D 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) =3D 128 <0.00003= 6> 23206 14:21:04.420543 ioctl(8, KVM_RUN 23203 14:21:04.420592 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000024> 23203 14:21:04.420739 write(6, "\0", 1) =3D 1 <0.000027> 23203 14:21:04.420828 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 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) =3D 128 <0.000021> 23203 14:21:04.421039 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000020> 23203 14:21:04.421181 write(6, "\0", 1) =3D 1 <0.000025> 23203 14:21:04.421264 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000052> 23203 14:21:04.421379 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000020> 23203 14:21:04.421457 read(10, "\3\0\0\0\0\0\0\0", 4096) =3D 8 <0.00001= 9> 23203 14:21:04.421538 read(10, 0xffa86510, 4096) =3D -1 EAGAIN (Resourc= e temporarily unavailable) <0.000019> 23203 14:21:04.421632 read(5, "\0\0\0", 512) =3D 3 <0.000047> 23203 14:21:04.421742 read(5, 0xffa87310, 512) =3D -1 EAGAIN (Resource = temporarily unavailable) <0.000052> 23203 14:21:04.421864 clock_gettime(CLOCK_MONOTONIC, {119262, 941710424= }) =3D 0 <0.000037> 23203 14:21:04.421959 gettimeofday({1284459664, 421983}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.422034 clock_gettime(CLOCK_MONOTONIC, {119262, 941862127= }) =3D 0 <0.000018> 23203 14:21:04.422108 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000020> 23203 14:21:04.422189 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000099> 23203 14:21:04.422413 clock_gettime(CLOCK_MONOTONIC, {119262, 942253027= }) =3D 0 <0.000022> 23203 14:21:04.422512 clock_gettime(CLOCK_MONOTONIC, {119262, 942342550= }) =3D 0 <0.000019> 23203 14:21:04.422589 clock_gettime(CLOCK_MONOTONIC, {119262, 942418192= }) =3D 0 <0.000018> 23203 14:21:04.422663 gettimeofday({1284459664, 422686}, NULL) =3D 0 <0= =2E000018> 23203 14:21:04.422737 clock_gettime(CLOCK_MONOTONIC, {119262, 942565097= }) =3D 0 <0.000018> 23203 14:21:04.422809 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000019> 23203 14:21:04.422890 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 925000}}, NULL) =3D 0 <0.000087> 23203 14:21:04.423100 clock_gettime(CLOCK_MONOTONIC, {119262, 942938261= }) =3D 0 <0.000021> 23203 14:21:04.423188 gettimeofday({1284459664, 423212}, NULL) =3D 0 <0= =2E000020> 23203 14:21:04.423273 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000026> 23203 14:21:04.423673 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000020> 23203 14:21:04.423861 write(6, "\0", 1) =3D 1 <0.000050> 23203 14:21:04.424008 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 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) =3D 128 <0.000022> 23203 14:21:04.424311 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000058> 23203 14:21:04.424521 write(6, "\0", 1) =3D 1 <0.000027> 23203 14:21:04.424607 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000020> 23203 14:21:04.424691 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000021> 23203 14:21:04.424771 clock_gettime(CLOCK_MONOTONIC, {119262, 944601250= }) =3D 0 <0.000020> 23203 14:21:04.424848 gettimeofday({1284459664, 424872}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.424923 clock_gettime(CLOCK_MONOTONIC, {119262, 944805889= }) =3D 0 <0.000048> 23203 14:21:04.425068 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000021> 23203 14:21:04.425152 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000075> 23203 14:21:04.425292 clock_gettime(CLOCK_MONOTONIC, {119262, 945121851= }) =3D 0 <0.000020> 23203 14:21:04.425372 clock_gettime(CLOCK_MONOTONIC, {119262, 945200578= }) =3D 0 <0.000019> 23203 14:21:04.425446 clock_gettime(CLOCK_MONOTONIC, {119262, 945278488= }) =3D 0 <0.000021> 23203 14:21:04.425524 gettimeofday({1284459664, 425548}, NULL) =3D 0 <0= =2E000020> 23203 14:21:04.425600 clock_gettime(CLOCK_MONOTONIC, {119262, 945428567= }) =3D 0 <0.000019> 23203 14:21:04.425674 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000019> 23203 14:21:04.425754 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 923000}}, NULL) =3D 0 <0.000019> 23203 14:21:04.425835 clock_gettime(CLOCK_MONOTONIC, {119262, 945663413= }) =3D 0 <0.000019> 23203 14:21:04.425909 gettimeofday({1284459664, 425932}, NULL) =3D 0 <0= =2E000018> 23203 14:21:04.425991 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000025> 23203 14:21:04.426388 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000019> 23203 14:21:04.426535 write(6, "\0", 1) =3D 1 <0.000027> 23203 14:21:04.426621 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 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) =3D 128 <0.000022> 23203 14:21:04.426946 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000057> 23203 14:21:04.427155 write(6, "\0", 1) =3D 1 <0.000026> 23203 14:21:04.427240 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000019> 23203 14:21:04.427322 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000020> 23203 14:21:04.427400 read(10, "\4\0\0\0\0\0\0\0", 4096) =3D 8 <0.00001= 9> 23203 14:21:04.427481 read(10, 0xffa86510, 4096) =3D -1 EAGAIN (Resourc= e temporarily unavailable) <0.000018> 23203 14:21:04.427555 read(5, "\0\0\0\0", 512) =3D 4 <0.000022> 23203 14:21:04.427635 read(5, 0xffa87310, 512) =3D -1 EAGAIN (Resource = temporarily unavailable) <0.000019> 23203 14:21:04.427709 clock_gettime(CLOCK_MONOTONIC, {119262, 947539408= }) =3D 0 <0.000020> 23203 14:21:04.429301 gettimeofday({1284459664, 429383}, NULL) =3D 0 <0= =2E000018> 23203 14:21:04.429442 clock_gettime(CLOCK_MONOTONIC, {119262, 949275654= }) =3D 0 <0.000014> 23203 14:21:04.429518 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000015> 23203 14:21:04.429598 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000017> 23203 14:21:04.429676 clock_gettime(CLOCK_MONOTONIC, {119262, 949504996= }) =3D 0 <0.000013> 23203 14:21:04.429750 clock_gettime(CLOCK_MONOTONIC, {119262, 949579332= }) =3D 0 <0.000014> 23203 14:21:04.429819 clock_gettime(CLOCK_MONOTONIC, {119262, 949647805= }) =3D 0 <0.000013> 23203 14:21:04.429891 gettimeofday({1284459664, 429914}, NULL) =3D 0 <0= =2E000013> 23203 14:21:04.429959 clock_gettime(CLOCK_MONOTONIC, {119262, 949787250= }) =3D 0 <0.000014> 23203 14:21:04.430025 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000013> 23203 14:21:04.430098 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 932000}}, NULL) =3D 0 <0.000015> 23203 14:21:04.430173 clock_gettime(CLOCK_MONOTONIC, {119262, 950001657= }) =3D 0 <0.000013> 23203 14:21:04.430240 gettimeofday({1284459664, 430263}, NULL) =3D 0 <0= =2E000013> 23203 14:21:04.430319 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000015> 23203 14:21:04.430546 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000014> 23203 14:21:04.430658 write(6, "\0", 1) =3D 1 <0.000017> 23203 14:21:04.430733 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000015> 23203 14:21:04.430810 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000014> 23203 14:21:04.430883 clock_gettime(CLOCK_MONOTONIC, {119262, 950713026= }) =3D 0 <0.000013> 23203 14:21:04.430952 gettimeofday({1284459664, 430975}, NULL) =3D 0 <0= =2E000013> 23203 14:21:04.431020 clock_gettime(CLOCK_MONOTONIC, {119262, 950848643= }) =3D 0 <0.000013> 23203 14:21:04.431091 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000014> 23203 14:21:04.431165 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000015> 23203 14:21:04.431241 clock_gettime(CLOCK_MONOTONIC, {119262, 951070442= }) =3D 0 <0.000014> 23203 14:21:04.431312 clock_gettime(CLOCK_MONOTONIC, {119262, 951141565= }) =3D 0 <0.000014> 23203 14:21:04.431381 clock_gettime(CLOCK_MONOTONIC, {119262, 951209628= }) =3D 0 <0.000014> 23203 14:21:04.431448 gettimeofday({1284459664, 431474}, NULL) =3D 0 <0= =2E000014> 23203 14:21:04.431519 clock_gettime(CLOCK_MONOTONIC, {119262, 951347952= }) =3D 0 <0.000013> 23203 14:21:04.431586 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000014> 23203 14:21:04.431662 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 932000}}, NULL) =3D 0 <0.000016> 23203 14:21:04.431740 clock_gettime(CLOCK_MONOTONIC, {119262, 951569525= }) =3D 0 <0.000014> 23203 14:21:04.431809 gettimeofday({1284459664, 431833}, NULL) =3D 0 <0= =2E000013> 23203 14:21:04.431897 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000015> 23203 14:21:04.432125 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000014> 23203 14:21:04.432233 write(6, "\0", 1) =3D 1 <0.000017> 23203 14:21:04.432305 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000014> 23203 14:21:04.432378 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000012> 23203 14:21:04.432444 read(10, "\2\0\0\0\0\0\0\0", 4096) =3D 8 <0.00001= 3> 23203 14:21:04.432518 read(10, 0xffa86510, 4096) =3D -1 EAGAIN (Resourc= e temporarily unavailable) <0.000013> 23203 14:21:04.432584 read(5, "\0\0", 512) =3D 2 <0.000014> 23203 14:21:04.432658 read(5, 0xffa87310, 512) =3D -1 EAGAIN (Resource = temporarily unavailable) <0.000012> 23203 14:21:04.432724 clock_gettime(CLOCK_MONOTONIC, {119262, 952551357= }) =3D 0 <0.000012> 23203 14:21:04.432789 gettimeofday({1284459664, 432811}, NULL) =3D 0 <0= =2E000012> 23203 14:21:04.432854 clock_gettime(CLOCK_MONOTONIC, {119262, 952681486= }) =3D 0 <0.000012> 23203 14:21:04.432919 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000013> 23203 14:21:04.432990 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000014> 23203 14:21:04.433062 clock_gettime(CLOCK_MONOTONIC, {119262, 952889944= }) =3D 0 <0.000012> 23203 14:21:04.433129 clock_gettime(CLOCK_MONOTONIC, {119262, 952957001= }) =3D 0 <0.000012> 23203 14:21:04.433194 clock_gettime(CLOCK_MONOTONIC, {119262, 953021746= }) =3D 0 <0.000012> 23203 14:21:04.433259 gettimeofday({1284459664, 433283}, NULL) =3D 0 <0= =2E000012> 23203 14:21:04.433327 clock_gettime(CLOCK_MONOTONIC, {119262, 953154033= }) =3D 0 <0.000013> 23203 14:21:04.433392 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000013> 23203 14:21:04.433463 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 936000}}, NULL) =3D 0 <0.000014> 23203 14:21:04.433535 clock_gettime(CLOCK_MONOTONIC, {119262, 953363023= }) =3D 0 <0.000013> 23203 14:21:04.433601 gettimeofday({1284459664, 433622}, NULL) =3D 0 <0= =2E000012> 23203 14:21:04.433670 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000013> 23203 14:21:04.433887 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000022> 23203 14:21:04.434089 write(6, "\0", 1) =3D 1 <0.000064> 23203 14:21:04.434247 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000052> 23203 14:21:04.434367 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000021> 23203 14:21:04.434456 clock_gettime(CLOCK_MONOTONIC, {119262, 954287414= }) =3D 0 <0.000020> 23203 14:21:04.434535 gettimeofday({1284459664, 434559}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.434610 clock_gettime(CLOCK_MONOTONIC, {119262, 954438671= }) =3D 0 <0.000019> 23203 14:21:04.434684 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000020> 23203 14:21:04.434766 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000023> 23203 14:21:04.434849 clock_gettime(CLOCK_MONOTONIC, {119262, 954678059= }) =3D 0 <0.000018> 23203 14:21:04.434929 clock_gettime(CLOCK_MONOTONIC, {119262, 954778987= }) =3D 0 <0.000040> 23203 14:21:04.435027 clock_gettime(CLOCK_MONOTONIC, {119262, 954856108= }) =3D 0 <0.000019> 23203 14:21:04.435101 gettimeofday({1284459664, 435125}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.435176 clock_gettime(CLOCK_MONOTONIC, {119262, 955004347= }) =3D 0 <0.000018> 23203 14:21:04.435276 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000019> 23203 14:21:04.435357 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 923000}}, NULL) =3D 0 <0.000020> 23203 14:21:04.435437 clock_gettime(CLOCK_MONOTONIC, {119262, 955265191= }) =3D 0 <0.000018> 23203 14:21:04.435510 gettimeofday({1284459664, 435533}, NULL) =3D 0 <0= =2E000018> 23203 14:21:04.435594 select(13, [0 5 7 9 10 12], [], [], {1, 0}) =3D 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) =3D 128 <0.000026> 23203 14:21:04.436037 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000054> 23203 14:21:04.436260 write(6, "\0", 1) =3D 1 <0.000028> 23203 14:21:04.436356 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 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) =3D 128 <0.000022> 23203 14:21:04.436661 rt_sigaction(SIGALRM, NULL, {0x80522d0, ~[KILL ST= OP RTMIN RT_1], 0}, 8) =3D 0 <0.000062> 23203 14:21:04.436874 write(6, "\0", 1) =3D 1 <0.000027> 23203 14:21:04.436960 write(11, "\1\0\0\0\0\0\0\0", 8) =3D 8 <0.000021> 23203 14:21:04.437045 read(12, 0xffa87480, 128) =3D -1 EAGAIN (Resource= temporarily unavailable) <0.000021> 23203 14:21:04.437123 read(10, "\3\0\0\0\0\0\0\0", 4096) =3D 8 <0.00002= 0> 23203 14:21:04.437205 read(10, 0xffa86510, 4096) =3D -1 EAGAIN (Resourc= e temporarily unavailable) <0.000018> 23203 14:21:04.437279 read(5, "\0\0\0", 512) =3D 3 <0.000023> 23203 14:21:04.437360 read(5, 0xffa87310, 512) =3D -1 EAGAIN (Resource = temporarily unavailable) <0.000019> 23203 14:21:04.437434 clock_gettime(CLOCK_MONOTONIC, {119262, 957264356= }) =3D 0 <0.000020> 23203 14:21:04.437511 gettimeofday({1284459664, 437535}, NULL) =3D 0 <0= =2E000019> 23203 14:21:04.437586 clock_gettime(CLOCK_MONOTONIC, {119262, 957414785= }) =3D 0 <0.000019> 23203 14:21:04.437660 timer_gettime(0x1, {it_interval=3D{0, 0}, it_valu= e=3D{0, 0}}) =3D 0 <0.000020> 23203 14:21:04.437743 timer_settime(0x1, 0, {it_interval=3D{0, 0}, it_v= alue=3D{0, 250000}}, NULL) =3D 0 <0.000091> 23203 14:21:04.437958 clock_gettime(CLOCK_MONOTONIC, {119262, 957798172= }) =3D 0 <0.000022> 23203 14:21:04.438054 clock_gettime(CLOCK_MONOTONIC, {119262, 957882793= }) =3D 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=3Dtap,ifname=3Dtap-kvm,id=3Dx \ -device virtio-net-pci,netdev=3Dx \ -monitor stdio \ -boot n \ -usbdevice tablet \ -m 1G \ -vnc :0 Yes, it does quite a lot of timer stuff... ;) Thanks! /mjt