Help: tasklet blocked for >8msec

Help: tasklet blocked for >8msec

[Tilman Schmidt]

[-- Attachment #1: Type: text/plain, Size: 1117 bytes --]

A user of the Gigaset base driver (drivers/isdn/gigaset/bas-gigaset.c)
reports his connection being dropped exactly every 30 seconds.
Analysis of his dmesg indicates that when the error occurs, both the
tasklets read_iso_tasklet and write_iso_tasklet handling the B channel
data stream (125 USB isochronous packets per second in each direction)
are at the same time not executed for an entire inter-packet interval,
ie. 8 msecs.

The machine in question, an Intel Core2 Duo E8600 with 4 GB RAM and
SATA hard disks, should really be fast enough. CPU load is negligible.
I have asked the user to recompile the kernel with CONFIG_PREEMPT=y
and to replace the calls to schedule_tasklet() for the two tasklets
by schedule_hi_tasklet(). That had no noticeable effect on the problem.

I would be grateful for any hint on what could be the cause for that
blockage and how to prevent it.

aTdHvAaNnKcSe
Tilman

-- 
Tilman Schmidt                    E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeöffnet mindestens haltbar bis: (siehe Rückseite)


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: Help: tasklet blocked for >8msec - USB mouse related

[Tilman Schmidt]

[-- Attachment #1: Type: text/plain, Size: 1360 bytes --]

/me wrote:
> A user of the Gigaset base driver (drivers/isdn/gigaset/bas-gigaset.c)
> reports his connection being dropped exactly every 30 seconds.
> Analysis of his dmesg indicates that when the error occurs, both the
> tasklets read_iso_tasklet and write_iso_tasklet handling the B channel
> data stream (125 USB isochronous packets per second in each direction)
> are at the same time not executed for an entire inter-packet interval,
> ie. 8 msecs.

The user did a bit of ellimination work, and it turned out that if
he disconnected his Logitech Laser Mouse from its USB port and
connected it to the PS2 port instead, the regular blockages ceased.

So we have a workaround, but no explanation.

This is on Debian Lenny with a 2.6.26 kernel. The user claims newer
kernels don't boot on his machine. Btw, he also reports that the
ISDN connection breaks each time he hotplugs any USB device, but
so far has failed to produce a syslog excerpt for that. (sigh)
The Motherboard is a Gigabyte GA-EP45T-EXTREME, advertised as
"Designed for overclocking enthusiasts with overwhelming
overclocking experience", which lets me fear the worst ...


-- 
Tilman Schmidt                    E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeöffnet mindestens haltbar bis: (siehe Rückseite)


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]

Re: Help: tasklet blocked for >8msec - USB mouse related

[Peter Zijlstra]

On Tue, 2009-03-31 at 18:52 +0200, Tilman Schmidt wrote:
> /me wrote:
> > A user of the Gigaset base driver (drivers/isdn/gigaset/bas-gigaset.c)
> > reports his connection being dropped exactly every 30 seconds.
> > Analysis of his dmesg indicates that when the error occurs, both the
> > tasklets read_iso_tasklet and write_iso_tasklet handling the B channel
> > data stream (125 USB isochronous packets per second in each direction)
> > are at the same time not executed for an entire inter-packet interval,
> > ie. 8 msecs.
> 
> The user did a bit of ellimination work, and it turned out that if
> he disconnected his Logitech Laser Mouse from its USB port and
> connected it to the PS2 port instead, the regular blockages ceased.
> 
> So we have a workaround, but no explanation.
> 
> This is on Debian Lenny with a 2.6.26 kernel. The user claims newer
> kernels don't boot on his machine. Btw, he also reports that the
> ISDN connection breaks each time he hotplugs any USB device, but
> so far has failed to produce a syslog excerpt for that. (sigh)
> The Motherboard is a Gigabyte GA-EP45T-EXTREME, advertised as
> "Designed for overclocking enthusiasts with overwhelming
> overclocking experience", which lets me fear the worst ...

Looks like the USB driver holds off interrupts for a long-long time. But
afaik that's not the only troublesome spot in mainline.

One way to test this would be using the threaded interrupt patches
Thomas posted, along with the USB driver conversion.

Another possible source might be SMIs -- and there's nothing much you
can do about those except bitch to Gigabyte.

But really, relying on <10ms execution latency on mainline is almost
asking for it -- in general we do better, but there are a few sore
spots.

Re: Help: tasklet blocked for >8msec - USB mouse related

[Tilman Schmidt]

[-- Attachment #1: Type: text/plain, Size: 2493 bytes --]

[CCing linux-usb as I had started another thread there already]

On Thu, 02 Apr 2009 11:43:59 +0200, Peter Zijlstra wrote:
> On Tue, 2009-03-31 at 18:52 +0200, Tilman Schmidt wrote:

>>> A user of the Gigaset base driver (drivers/isdn/gigaset/bas-gigaset.c)
>>> reports his connection being dropped exactly every 30 seconds.
>>> Analysis of his dmesg indicates that when the error occurs, both the
>>> tasklets read_iso_tasklet and write_iso_tasklet handling the B channel
>>> data stream (125 USB isochronous packets per second in each direction)
>>> are at the same time not executed for an entire inter-packet interval,
>>> ie. 8 msecs.
>> The user did a bit of ellimination work, and it turned out that if
>> he disconnected his Logitech Laser Mouse from its USB port and
>> connected it to the PS2 port instead, the regular blockages ceased.
> 
> Looks like the USB driver holds off interrupts for a long-long time.

Well, not quite. The sequence of events is this:
- two isochronous read URBs are queued
- completion handler is called for the first one
- schedules tasklet for bottom half processing of received data
- submits another URB so that there are again two URBs queued
- 8 ms later, completion handler is called again for the next URB
- notices previous URB hasn't been processed (ie. tasklet hasn't run)
- bitches
And the same, mutatis mutandis, for the sending direction.

So interrupts seem to be delivered fine, it's just the tasklets that are
held off.

> Another possible source might be SMIs -- and there's nothing much you
> can do about those except bitch to Gigabyte.
> 
> But really, relying on <10ms execution latency on mainline is almost
> asking for it -- in general we do better, but there are a few sore
> spots.

Interestingly, I never encountered that sort of problem while developing
the driver, on a lowly 700 MHz P3 with kernels around 2.6.11, and the only
problem report I ever received in that area until now was from a user who
ran an IDE disk in PIO mode, and whose problems vanished once he switched
that to DMA mode.

So what do you propose? Queue more URBs, so that I can tolerate waiting
longer for bottom half processing to kick in? How much time will I have
to be able to tolerate?

Thanks,
Tilman

-- 
Tilman Schmidt                    E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeöffnet mindestens haltbar bis: (siehe Rückseite)


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 254 bytes --]