Re: USB performance bug since kernel 2.6.13 (CRITICAL???)

Re: USB performance bug since kernel 2.6.13 (CRITICAL???)

[Open Source]

Hi Wolfgang (and all),

Thanks for the input.  However, I am not understanding
exactly why kernel mode is treated any differently than
user mode for this sort of thing.  I am looking at the code
in ehci-q.c and ehci-hcd.c.

It seems like the unlinking of completed URBs
happens asynchronously on a timer.  This is a
surprise to me since I thought this was happening
on an IRQ from the host controller.  But if what I'm
surmising is correct it would explain everything
I am seeing.  I'm not able to ascertain how
user mode drivers are treated differently than
kernel mode drivers in this regard.  From what I
can tell, all drivers would be broken equally!
Can anyone who has more experience
with this code confirm this for me?
  
Besides, we count on sub-10 ms response times all the
time in user mode.  Take for example, the access of a file.
If opening a file had a fixed latency of 4 ms, people
would be up in arms.  So that's not entirely a valid excuse.
A USB operation that used to take 1 ms now takes 4 ms.
That's a pretty big change.

The ability to write user-mode drivers for USB devices
is very powerful for deployment.  If one writes a kernel
driver, there are severe deployment hassles.  As such,
my company has chosen to write user-mode drivers
on both Windows to avoid driver deployment nightmares.
This has been extremely successful so far..  Ironically,
Windows (using libusb-win32) has had no such performance
glitches. As a matter of principle, Linux should at least be
as good as Windows, right?

Hopefully we can get this sorted out.

Cheers.


----- Original Message ----
From: WolfgangMües <wolfgang@iksw-muees.de>
To: linux-usb-devel@lists.sourceforge.net
Sent: Friday, October 13, 2006 12:11:08 PM
Subject: Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

On Friday 13 October 2006 19:20, Open Source wrote:
> Alan -- yes, I understand the ability to increase throughput
> by transfering more bytes and I am definitely able to see
> better overall throughput when increasing the number
> of bytes per transaction.  However, I needs to still have
> good transaction-level timing because I cannot always
> queue the transactions up.  Recall that each transaction
> is a WRITE followed by a READ.  The results of the
> READ determine the outgoing bytes for the following
> transaction's WRITE.

Relying on sub-10ms response times in userspace is broken by design.

I have written a driver with similar timing requirements, and I have 
done it in the kernel. This is the right way to go. Nothing else.

regards

Wolfgang
-- 
Das Leben kann nur rückwärts verstanden,
muß aber vorwärts gelebt werden.

-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
linux-usb-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Alan Stern]

On Fri, 13 Oct 2006, Open Source wrote:

> Hi Wolfgang (and all),
> 
> Thanks for the input.  However, I am not understanding
> exactly why kernel mode is treated any differently than
> user mode for this sort of thing.  I am looking at the code
> in ehci-q.c and ehci-hcd.c.
> 
> It seems like the unlinking of completed URBs
> happens asynchronously on a timer.  This is a
> surprise to me since I thought this was happening
> on an IRQ from the host controller.  But if what I'm
> surmising is correct it would explain everything
> I am seeing.  I'm not able to ascertain how
> user mode drivers are treated differently than
> kernel mode drivers in this regard.  From what I
> can tell, all drivers would be broken equally!
> Can anyone who has more experience
> with this code confirm this for me?

I don't think so.  You must be mis-reading the code.  The only timers used 
in ehci-hcd are a couple of watchdogs; they shouldn't affect the normal 
URB completions which occur within ehci_work(), called by ehci_irq().

What Wolfgang meant was that user processes are subject to unpredictable 
delays from all kinds of sources.

Alan Stern

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[David Brownell]

On Friday 13 October 2006 12:31 pm, Open Source wrote:
> 
> It seems like the unlinking of completed URBs
> happens asynchronously on a timer.  This is a
> surprise to me since I thought this was happening
> on an IRQ from the host controller.  But if what I'm
> surmising is correct it would explain everything
> I am seeing.

You didn't say what EHCI controller you're using.

The original reason for that timer was specifically
to handle bugs in VIA silicon:  that won't always issue
all of the IRQs it's supposed to.  Specifically the IAA
IRQ would never arrive, leading to unlink operations
wedging.

Later on that timer got overloaded (and hence it got
to be a bit of a mess) with two other tasks:

(a) deducing that an endpoint had been idle long enough
to take off the ring of active control/bulk queues,
which is what ensures that an idle controller isn't
wasting memory bandwidth by doing DMA all the time.

(It turns out to be a Bad Idea to take idle endpoints
off that ring the instant they become idle, since they
will as a rule be reused very quickly ... so immediate
removal slows things down a lot.  Plus it chases an
annoying number of races between driver and controller.)

(b) being a general I/O watchdog, since there were some
other (rare) cases where IRQs would appear to get lost


In short, except for (a) the only reason I know of
that changing HZ should affect system performance is
IRQ lossage ... of which the primary reason has always
been strange behavior from VIA controllers.

- Dave

 

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Open Source]

Hi Alan and all,

I have run the "strace -r -f" as you had recommended
and the problem revealed itself.  I did some cross-checking
and I'm pretty sure I have found the issue.

Basically, I was barking up the wrong tree in assuming
this was a USB subsystem issue.  As people correctly
pointed out, the change to CONFIG_HZ has affected
many things.  In my case, I was using a library that issued
a nanosleep for a particular amount of time. Most often
the sleep time is 0, but the library was still calling
nanosleep({0, 0}).  This seemed to put the running process
to sleep (for 0 time) but it only was woken up at the next
timer interrupt (1 ms period for pre-2.6.13 and 4 ms for
2.6.13 and up).

I do not know if this is the desired behavior of nanosleep.
 For example, In Windows, calling Sleep with a zero time,
and no other processes hogging the CPU, does not seem
illicit the same effect as in Linux.  There, no time is
expended.  However, I can understand that there could
be technical reasons to leave nanosleep's behavior like this.

In any case, I apologize for causing ruckus and shifting
the blame incorrectly to USB.  Thank you all for your
advice.  I wouldn't have been able to narrow it down so
easily without it, especially the use of "strace -r" which is
something very useful that I did not know despite
developing on Linux for over a decade!

Furthermore, I am very glad to know that this is not one
of those user-mode-issues-that-can-only-be-solved-by-going-
to-kernel-mode. At least my intuition was correct there.  Things
should be snappy if no other processes are running on the system,
even if the application is in user mode!

Also, here are a few articles that might be useful to other
scheduler newbies like myself:

] http://josh.trancesoftware.com/linux/linux_cpu_scheduler.pdf
] http://kerneltrap.org/node/5411

Thanks again.
Satisfied Open Source Fan


----- Original Message ----
From: Alan Cox <alan@lxorguk.ukuu.org.uk>
To: Open Source <opensource3141@yahoo.com>
Cc: Alan Stern <stern@rowland.harvard.edu>; linux-usb-devel@lists.sourceforge.net; WolfgangMües <wolfgang@iksw-muees.de>; linux-kernel@vger.kernel.org
Sent: Friday, October 13, 2006 4:41:44 PM
Subject: Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

Ar Gwe, 2006-10-13 am 16:02 -0700, ysgrifennodd Open Source:
> clear understanding of what is causing it.  As it stands it doesn't
> seem like even the experts know exactly where this
> delay is being caused.

strace should tell you precisely how long each syscall takes if you ask
it to trace things nicely. If you have code trying to wait for a tiny
time then HZ will bump the wait to be longer (kernel or user) but for
other cases all should be fine either way.

The other issues like priority and paging caused delays can generally be
dealt with by having the relevant service code running mlockall and real
time priority.

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Alan Stern]

On Sat, 14 Oct 2006, Alan Cox wrote:

> Ar Gwe, 2006-10-13 am 16:30 -0700, ysgrifennodd Open Source:
> > There is an ioctl that is waiting for the URB to be reaped.
> > I am almost certain it is this syscall that is taking 4 ms (as
> > opposed to 1 ms with CONFIG_HZ=1000).
> 
> What does strace say about it ? This is measurable not speculation.

I completely agree with the other Alan.  You don't have to guess about
these things.  Use strace to see what your process is doing and at the
same time use usbmon to see what the USB stack is doing.  Run the 
experiment at both 1000 Hz and 250 Hz and compare the results.

Alan Stern

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Alan Cox]

Ar Gwe, 2006-10-13 am 16:02 -0700, ysgrifennodd Open Source:
> clear understanding of what is causing it.  As it stands it doesn't
> seem like even the experts know exactly where this
> delay is being caused.

strace should tell you precisely how long each syscall takes if you ask
it to trace things nicely. If you have code trying to wait for a tiny
time then HZ will bump the wait to be longer (kernel or user) but for
other cases all should be fine either way.

The other issues like priority and paging caused delays can generally be
dealt with by having the relevant service code running mlockall and real
time priority.

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Open Source]

Hi Alan,

Yes, user mode processes are susceptible to other delays,
but that's really not the problem here.  My application is
*clearly* being hit by this difference in CONFIG_HZ.
All the evidence points to this fact.

People often bring this up user mode versus kernel
mode as a criticism when it doesn't really apply.
All I was saying is that we should get away
from the talk of kernel versus user mode and narrow
the problem to something more specific.

As for the issue regarding ehci_work and ehci_irq:
There are many many comments in the code that say
that urb linking happens asynchronously.  It is hard for
me to fully appreciate how everything is put together
because I am not an expert with the host controller code
in the kernel. Is there some way we can get to the bottom of this?

Either the problem is in the ehci code or in devio.c.  In
devio.c the user space process calls an ioctl to reap the
urb (blocking until it is complete).  The asynchronous
callback for the urb is called when the urb is unlinked
and that callback (async_completed in devio.c) signals
the wait object that the ioctl has added to the wait queue.
But, I don't see anything inherently wrong with how things
are setup there.

In any case, something is wrong.  I want to be as helpful
as possible to get to the bottom of this, but it might be tough
to do it without some insight from the gurus who wrote this code.
Even if the problem will be hard to fix, we should have a
clear understanding of what is causing it.  As it stands it doesn't
seem like even the experts know exactly where this
delay is being caused.

Thanks.


----- Original Message ----
From: Alan Stern <stern@rowland.harvard.edu>
To: Open Source <opensource3141@yahoo.com>
Cc: WolfgangMües <wolfgang@iksw-muees.de>; linux-usb-devel@lists.sourceforge.net; linux-kernel@vger.kernel.org
Sent: Friday, October 13, 2006 2:08:46 PM
Subject: Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

On Fri, 13 Oct 2006, Open Source wrote:

> Hi Wolfgang (and all),
> 
> Thanks for the input.  However, I am not understanding
> exactly why kernel mode is treated any differently than
> user mode for this sort of thing.  I am looking at the code
> in ehci-q.c and ehci-hcd.c.
> 
> It seems like the unlinking of completed URBs
> happens asynchronously on a timer.  This is a
> surprise to me since I thought this was happening
> on an IRQ from the host controller.  But if what I'm
> surmising is correct it would explain everything
> I am seeing.  I'm not able to ascertain how
> user mode drivers are treated differently than
> kernel mode drivers in this regard.  From what I
> can tell, all drivers would be broken equally!
> Can anyone who has more experience
> with this code confirm this for me?

I don't think so.  You must be mis-reading the code.  The only timers used 
in ehci-hcd are a couple of watchdogs; they shouldn't affect the normal 
URB completions which occur within ehci_work(), called by ehci_irq().

What Wolfgang meant was that user processes are subject to unpredictable 
delays from all kinds of sources.

Alan Stern

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Bob Copeland]

On 10/13/06, Open Source <opensource3141@yahoo.com> wrote:

> p.s. My apologies about the word wrap.  I'm using
> a different mail client than my usual one and didn't
> realize it was not wrapping automatically.

Why all the cloak and dagger?  You could at least make up a real name.

Bob

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Alan Stern]

On Fri, 13 Oct 2006, Open Source wrote:

> Hi all,
> 
> I just tested using CONFIG_HZ_1000=y and
> CONFIG_HZ=1000 and as expected, this change
> improves the throughput.  Thank you Lee for pointing
> that out so quickly.
> 
> Alan -- yes, I understand the ability to increase throughput
> by transfering more bytes and I am definitely able to see
> better overall throughput when increasing the number
> of bytes per transaction.  However, I needs to still have
> good transaction-level timing because I cannot always
> queue the transactions up.  Recall that each transaction
> is a WRITE followed by a READ.  The results of the
> READ determine the outgoing bytes for the following
> transaction's WRITE.
> 
> Not to sound like a broken record, but there is something
> seriously wrong here.  This has to be a bug somewhere.
> It could be very well just be something as simple as
> issuing the right incantation with libusb, devio, etc.  But,
> I've been using libusb for years now and am at a loss
> on what might have changed to require this.
> 
> Any ideas???

Try using usbmon to get a detailed record of events with high-precision
timestamps.  Maybe also add similar logging to your program.  This may
suggest some ideas about where the slowdown originates.

It's possible that some process you're unaware of is using the CPU, and 
the reduced clock rate increases the latency for your process to continue 
running.

Alan Stern

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Open Source]

Hi all,

I just tested using CONFIG_HZ_1000=y and
CONFIG_HZ=1000 and as expected, this change
improves the throughput.  Thank you Lee for pointing
that out so quickly.

Alan -- yes, I understand the ability to increase throughput
by transfering more bytes and I am definitely able to see
better overall throughput when increasing the number
of bytes per transaction.  However, I needs to still have
good transaction-level timing because I cannot always
queue the transactions up.  Recall that each transaction
is a WRITE followed by a READ.  The results of the
READ determine the outgoing bytes for the following
transaction's WRITE.

Not to sound like a broken record, but there is something
seriously wrong here.  This has to be a bug somewhere.
It could be very well just be something as simple as
issuing the right incantation with libusb, devio, etc.  But,
I've been using libusb for years now and am at a loss
on what might have changed to require this.

Any ideas???


Best regards.


p.s. My apologies about the word wrap.  I'm using
a different mail client than my usual one and didn't
realize it was not wrapping automatically.


----- Original Message ----
From: Alan Stern <stern@rowland.harvard.edu>
To: Open Source <opensource3141@yahoo.com>
Cc: linux-usb-devel@lists.sourceforge.net; linux-kernel@vger.kernel.org
Sent: Friday, October 13, 2006 6:56:31 AM
Subject: Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[FYI, it would make things easier for the rest of us if you can convince 
your email client to wrap lines before 80 columns.]

I'll be interested to here if changing HZ back to 1000 makes any 
difference.  As others have already stated, it shouldn't matter but maybe 
it does somehow.

Even if it does, there are things you might be able to do with HZ=250 to 
improve throughput.  You could transfer more than 512/1024 bytes per URB.  
You could queue multiple URBs before waiting for the first one to 
complete.  Provided you can keep the endpoint queues filled, you should be 
able to achieve the maximum throughput of the hardware.

Alan Stern

Re: [linux-usb-devel] USB performance bug since kernel 2.6.13 (CRITICAL???)

[Alan Stern]

[FYI, it would make things easier for the rest of us if you can convince 
your email client to wrap lines before 80 columns.]

On Thu, 12 Oct 2006, Open Source wrote:

> Hi all, 
>  I am writing regarding a performance issue that I recently observed
> after upgrading from kernel 2.6.12 to 2.6.17.  I did some hunting around
> and have found that the issue first arises in 2.6.13.
> 
> I am using a device that submits URBs asynchronously using the libusb
> devio infrastructure.  In version 2.6.12 I am able to submit and reap
> URBs for my particular application at a transaction rate of one per
> millisecond.  A transaction consists of a single WRITE URB (< 512 bytes)
> followed by a single READ URB (1024 bytes).  Once I upgrade to version
> 2.6.13, the transactional rate drops to one per 4 milliseconds!
> 
> The overall performance of a particular algorithm is increased from a
> total execution time of 75 seconds to over 160 seconds.  The only
> difference between the two tests is the kernel.  Microsoft Windows
> executes the algorithm in 70-75 seconds!
> 
> I am using a Fedora Core distribution with FC4 kernels for testing.  Is
> there some new incantation that is required in my user-mode driver to
> get around a "feature" in recent kernels?  Does anyone else know about
> this?  I was not able to easily find discussion about this on the
> newsgroups.  It appears that this problem has been around for a while,
> if it is indeed a problem.

I'll be interested to here if changing HZ back to 1000 makes any 
difference.  As others have already stated, it shouldn't matter but maybe 
it does somehow.

Even if it does, there are things you might be able to do with HZ=250 to 
improve throughput.  You could transfer more than 512/1024 bytes per URB.  
You could queue multiple URBs before waiting for the first one to 
complete.  Provided you can keep the endpoint queues filled, you should be 
able to achieve the maximum throughput of the hardware.

Alan Stern