Re: high load with usb device

[Avi Kivity <avi@redhat.com>]

  On 09/14/2010 03:29 PM, Michael Tokarev wrote:
> 14.09.2010 17:25, Avi Kivity wrote:
> >   On 09/14/2010 03:15 PM, Michael Tokarev wrote:
> []
> >>  Looking at what hw/usb-uhci.c:uhci_frame_timer() routine
> >>  does, it is quite expected to have that many writes and
> >>  reads and that many gettimers().  It is polling for events
> >>  every 1/1000th of a second, instead of using some form of
> >>  select().
> >
> >  IIUC that's mandated by USB hardware.  The guest may place data in
> >  memory, and USB polls it to see if it needs to tell send some message on
> >  the bus.
>
> Well, checking guest memory does not involve so many
> reads/writes, i guess ;)
>
> >  Please post an strace again, this time with -e trace=select.  Looks like
> >  each timer callback results in>50 syscalls, 4 of which are select()s).
>
> Here we go.
>
> qemu-syst 25728  mjt    0u   CHR    136,9      0t0       12 /dev/pts/9
> qemu-syst 25728  mjt    1u   CHR    136,9      0t0       12 /dev/pts/9
> qemu-syst 25728  mjt    2u   CHR    136,9      0t0       12 /dev/pts/9
> qemu-syst 25728  mjt    3u   CHR   10,232      0t0     4402 /dev/kvm
> qemu-syst 25728  mjt    4u  0000      0,9        0      607 anon_inode
> qemu-syst 25728  mjt    5r  FIFO      0,8      0t0 11703862 pipe
> qemu-syst 25728  mjt    6w  FIFO      0,8      0t0 11703862 pipe
> qemu-syst 25728  mjt    7u   CHR   10,200      0t0     1228 /dev/net/tun
> qemu-syst 25728  mjt    8u  0000      0,9        0      607 anon_inode
> qemu-syst 25728  mjt    9u  IPv4 11704055      0t0      TCP *:5900 (LISTEN)
> qemu-syst 25728  mjt   10u  0000      0,9        0      607 anon_inode
> qemu-syst 25728  mjt   11u  0000      0,9        0      607 anon_inode
> qemu-syst 25728  mjt   12u  0000      0,9        0      607 anon_inode
>
> 17:27:23.995096 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 998573})<0.001461>
> 17:27:23.996994 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999987})<0.000042>
> 17:27:23.997258 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999998})<0.000011>
> 17:27:23.997561 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999998})<0.000009>
> 17:27:23.997739 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 998771})<0.001256>
> 17:27:23.999458 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999991})<0.000017>
> 17:27:23.999665 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999998})<0.000010>
> 17:27:23.999996 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999998})<0.000009>
> 17:27:24.000199 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 998775})<0.001241>
> 17:27:24.001666 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999997})<0.000006>
> 17:27:24.001768 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 999932})<0.000103>
> 17:27:24.001985 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 2 (in [5 10], left {0, 999998})<0.000005>
> 17:27:24.002061 select(13, [0 5 7 9 10 12], [], [], {1, 0}) = 1 (in [12], left {0, 998407})<0.001617>
>

That pipe is doing a lot of damage (I don't have it, and couldn't 
reproduce your results, another pointer).  Do you have CONFIG_EVENTFD 
set?  If not, why not?

-- 
error compiling committee.c: too many arguments to function